Feb 26 22:26:14 loe volumio[3912]: info: CoreCommandRouter::volumioPause Feb 26 22:26:14 loe volumio[3912]: info: CoreStateMachine::pause Feb 26 22:26:20 loe volumio[3912]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 26 22:26:20 loe volumio[3912]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 26 22:26:21 loe volumio[3912]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:26:21 loe volumio[3912]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 26 22:26:21 loe volumio[3912]: info: Getting Alsa Cards List without I2S DAC Feb 26 22:26:21 loe volumio[3912]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Feb 26 22:26:21 loe volumio[3912]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:26:21 loe volumio[3912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 22:26:21 loe volumio[3912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 22:26:21 loe volumio[3912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 22:26:21 loe volumio[3912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 22:26:21 loe volumio[3912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 22:26:21 loe volumio[3912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 22:26:21 loe volumio[3912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 22:26:21 loe volumio[3912]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Feb 26 22:26:21 loe volumio[3912]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 26 22:26:23 loe volumio[3912]: info: Executing endpoint metavolumio Feb 26 22:26:23 loe volumio[3912]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 26 22:26:23 loe volumio[3912]: info: Executing endpoint metavolumio Feb 26 22:26:23 loe volumio[3912]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 26 22:26:40 loe volumio[3912]: info: Executing endpoint metavolumio Feb 26 22:26:40 loe volumio[3912]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 26 22:26:40 loe volumio[3912]: info: Executing endpoint metavolumio Feb 26 22:26:40 loe volumio[3912]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 26 22:26:53 loe go-librespot[4226]: time="2026-02-26T22:26:53+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 26 22:26:53 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:26:53 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:26:53 loe volumio[3912]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Feb 26 22:26:53 loe volumio[3912]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Feb 26 22:26:53 loe volumio[3912]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Feb 26 22:26:53 loe volumio[3912]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Feb 26 22:26:53 loe volumio[3912]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Feb 26 22:26:53 loe volumio[3912]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Feb 26 22:26:53 loe volumio[3912]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 22:26:53 loe volumio[3912]: Error: socket hang up Feb 26 22:26:53 loe volumio[3912]: at connResetException (node:internal/errors:720:14) Feb 26 22:26:53 loe volumio[3912]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 26 22:26:53 loe volumio[3912]: at Socket.emit (node:events:526:35) Feb 26 22:26:53 loe volumio[3912]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 26 22:26:53 loe volumio[3912]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 26 22:26:53 loe volumio[3912]: code: 'ECONNRESET', Feb 26 22:26:53 loe volumio[3912]: response: undefined Feb 26 22:26:53 loe volumio[3912]: } Feb 26 22:26:53 loe volumio[3912]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 22:26:54 loe sudo[5772]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-26 22:25' Feb 26 22:26:54 loe sudo[5772]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:26:54 loe sudo[5772]: pam_unix(sudo:session): session closed for user root Feb 26 22:26:55 loe volumio-remote-updater[708]: [2026-02-26 22:26:55] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 26 22:26:55 loe volumio-remote-updater[708]: [2026-02-26 22:26:55] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 26 22:26:55 loe vtcs[4469]: [2026-02-26 22:26:55.133] [tisoc] [error] [SpkconServer.cpp:378] recv error. socket disconnected Feb 26 22:26:55 loe qobuz-connect[4451]: 20260226 22:26:55.133 [4451.4451] INFO SampleApp: Socket closed Feb 26 22:26:55 loe systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:26:55 loe volumio5-onboarding[2759]: time=2026-02-26T22:26:55.135+01:00 level=ERROR msg="failed reading message" component=volumio/socket error="websocket: close 1006 (abnormal closure): unexpected EOF" Feb 26 22:26:55 loe volumio5-onboarding[2759]: time=2026-02-26T22:26:55.138+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 26 22:26:55 loe bluealsa[1018]: ../src/ba-transport-pcm.c:453: Closing PCM: 16 Feb 26 22:26:55 loe bluealsa[1018]: ../src/ba-transport.c:203: PCM clients check keep-alive: 0 ms Feb 26 22:26:55 loe systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 26 22:26:55 loe systemd[1]: volumio.service: Consumed 1min 52.568s CPU time. Feb 26 22:26:55 loe systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 26 22:26:55 loe systemd[1]: dynamicswap.service: Deactivated successfully. Feb 26 22:26:55 loe systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4. Feb 26 22:26:55 loe systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 26 22:26:55 loe systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 26 22:26:55 loe systemd[1]: volumio.service: Consumed 1min 52.568s CPU time. Feb 26 22:26:55 loe systemd[1]: Started volumio.service - Volumio Backend Module. Feb 26 22:26:55 loe systemd[1]: dynamicswap.service: Deactivated successfully. Feb 26 22:26:56 loe volumio5-onboarding[2759]: time=2026-02-26T22:26:56.141+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 26 22:26:56 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 26 22:26:56 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:26:56 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:26:56 loe go-librespot[5815]: go-librespot daemon starting... Feb 26 22:26:56 loe go-librespot[5816]: time="2026-02-26T22:26:56+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:26:56 loe go-librespot[5816]: time="2026-02-26T22:26:56+01:00" level=debug msg="app state loaded" Feb 26 22:26:56 loe go-librespot[5816]: time="2026-02-26T22:26:56+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:26:57 loe go-librespot[5816]: time="2026-02-26T22:26:57+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:26:57 loe go-librespot[5816]: time="2026-02-26T22:26:57+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:26:57 loe go-librespot[5816]: time="2026-02-26T22:26:57+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:26:57 loe go-librespot[5816]: time="2026-02-26T22:26:57+01:00" level=info msg="zeroconf server listening on port 37645" Feb 26 22:26:57 loe volumio5-onboarding[2759]: time=2026-02-26T22:26:57.146+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 26 22:26:57 loe go-librespot[5816]: time="2026-02-26T22:26:57+01:00" level=debug msg="obtained new client token: AAA7QhmIFx2IYIwGVLHwfr/ukNd/+2B2L/NQXmgTbzFIr/yT0qmKCdS4LzKwrO12+mBW56wK44wfMOAmT2QDnUi+kJkEbEjaQTz2hbwErgS0H339YnSwFZmL9nhaGOufCtMvkPneVsSbF27Hr+TWvOTEdhKwQ7IvgTkdck7a4zMDHL+nQyfUtbJ9tZCaYtZwdEyJUo712/SF8dJ/6MKht81TubvLKFLjdFsYVdlGmscptoKR5pEAh50=" Feb 26 22:26:57 loe go-librespot[5816]: time="2026-02-26T22:26:57+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:26:57 loe go-librespot[5816]: time="2026-02-26T22:26:57+01:00" level=debug msg="completed keyexchange" Feb 26 22:26:57 loe go-librespot[5816]: time="2026-02-26T22:26:57+01:00" level=debug msg="completed challenge" Feb 26 22:26:57 loe go-librespot[5816]: time="2026-02-26T22:26:57+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:26:57 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:26:57 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:26:58 loe volumio5-onboarding[2759]: time=2026-02-26T22:26:58.149+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 26 22:26:59 loe volumio[5800]: info: ------------------------------------------- Feb 26 22:26:59 loe volumio[5800]: info: ----- Volumio3 ---- Feb 26 22:26:59 loe volumio[5800]: info: ------------------------------------------- Feb 26 22:26:59 loe volumio[5800]: info: ----- System startup ---- Feb 26 22:26:59 loe volumio[5800]: info: ------------------------------------------- Feb 26 22:26:59 loe ntpd[879]: PROTO: 84.27.222.8 unlink local addr 192.168.178.145 -> Feb 26 22:27:00 loe volumio-remote-updater[708]: [2026-02-26 22:27:00] [connect] Successful connection Feb 26 22:27:00 loe volumio[5800]: info: MYVOLUMIO Environment detected Feb 26 22:27:00 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 26 22:27:00 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:00 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:00 loe go-librespot[5832]: go-librespot daemon starting... Feb 26 22:27:00 loe volumio[5800]: info: Plugin folders cleanup Feb 26 22:27:00 loe volumio[5800]: info: Scanning into folder /volumio/app/plugins/ Feb 26 22:27:00 loe volumio[5800]: info: Scanning category audio_interface Feb 26 22:27:00 loe volumio[5800]: info: Scanning category miscellanea Feb 26 22:27:00 loe go-librespot[5833]: time="2026-02-26T22:27:00+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:27:00 loe go-librespot[5833]: time="2026-02-26T22:27:00+01:00" level=debug msg="app state loaded" Feb 26 22:27:00 loe go-librespot[5833]: time="2026-02-26T22:27:00+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:27:00 loe volumio[5800]: info: Scanning category music_service Feb 26 22:27:00 loe volumio[5800]: info: Scanning category plugins.json Feb 26 22:27:00 loe volumio[5800]: info: Scanning category system_controller Feb 26 22:27:00 loe volumio[5800]: info: Scanning category user_interface Feb 26 22:27:00 loe volumio[5800]: info: Scanning into folder /data/plugins/ Feb 26 22:27:00 loe volumio[5800]: info: Scanning category music_service Feb 26 22:27:00 loe volumio[5800]: info: Plugin folders cleanup completed Feb 26 22:27:00 loe volumio[5800]: info: ------------------------------------------- Feb 26 22:27:00 loe volumio[5800]: info: ----- Core plugins startup ---- Feb 26 22:27:00 loe volumio[5800]: info: ------------------------------------------- Feb 26 22:27:00 loe volumio[5800]: info: Loading plugins from folder /volumio/app/plugins/ Feb 26 22:27:00 loe volumio[5800]: info: Adding plugin upnp to MyMusic Plugins Feb 26 22:27:00 loe volumio[5800]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 26 22:27:00 loe volumio[5800]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 26 22:27:00 loe volumio[5800]: info: Loading plugins from folder /data/plugins/ Feb 26 22:27:00 loe volumio[5800]: info: Loading plugin "system"... Feb 26 22:27:00 loe volumio[5800]: info: Loading plugin "appearance"... Feb 26 22:27:01 loe go-librespot[5833]: time="2026-02-26T22:27:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:27:01 loe go-librespot[5833]: time="2026-02-26T22:27:01+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:27:01 loe go-librespot[5833]: time="2026-02-26T22:27:01+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:27:01 loe go-librespot[5833]: time="2026-02-26T22:27:01+01:00" level=info msg="zeroconf server listening on port 42577" Feb 26 22:27:01 loe go-librespot[5833]: time="2026-02-26T22:27:01+01:00" level=debug msg="obtained new client token: AADPAArhw0l9CVUyqOoUCQfa+2IzA/FtgA2gpLWm8NCaalU3+R7+y/c7E5pV6KZh6Y3SXDNRhgvkdaHYLefhhOtbRFM0QOQNIdWi24wcVeW/4wtdrHbDBVRPJ4MctOUWgsl/lvlv0HJyYCFWI6KPLL0/GWS+QOlUhMfsJG6oL2EXr5b+HKO9mj3EWNpZbPmj1uHX8AY1y2io7p6fh5q7udBiTCYWuM8ryqeda/BhGSGndHx0wrKaorc=" Feb 26 22:27:01 loe go-librespot[5833]: time="2026-02-26T22:27:01+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:27:01 loe go-librespot[5833]: time="2026-02-26T22:27:01+01:00" level=debug msg="completed keyexchange" Feb 26 22:27:01 loe go-librespot[5833]: time="2026-02-26T22:27:01+01:00" level=debug msg="completed challenge" Feb 26 22:27:01 loe go-librespot[5833]: time="2026-02-26T22:27:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:27:01 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:27:01 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:27:02 loe volumio[5800]: info: Loading plugin "network"... Feb 26 22:27:02 loe volumio[5800]: info: Refreshing Cached IP Addresses Feb 26 22:27:02 loe sudo[5844]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 26 22:27:02 loe sudo[5844]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:02 loe sudo[5846]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 26 22:27:02 loe sudo[5846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:02 loe volumio[5800]: info: Loading plugin "services"... Feb 26 22:27:02 loe sudo[5844]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:02 loe volumio[5800]: info: Loading plugin "volumio5onboarding"... Feb 26 22:27:02 loe sudo[5846]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:02 loe volumio[5800]: info: Loading plugin "alsa_controller"... Feb 26 22:27:02 loe sudo[5854]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 26 22:27:02 loe sudo[5854]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:02 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 26 22:27:02 loe volumio[5800]: info: Loading plugin "wizard"... Feb 26 22:27:02 loe volumio[5800]: info: Loading plugin "networkfs"... Feb 26 22:27:03 loe volumio[5800]: info: Starting Udev Watcher for removable devices Feb 26 22:27:03 loe volumio[5800]: info: Ignoring mount for partition: boot Feb 26 22:27:03 loe volumio[5800]: info: Ignoring mount for partition: volumio Feb 26 22:27:03 loe volumio[5800]: info: Ignoring mount for partition: volumio_data Feb 26 22:27:03 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 26 22:27:03 loe volumio[5800]: info: Loading plugin "volumio_command_line_client"... Feb 26 22:27:03 loe volumio[5800]: info: Loading plugin "upnp"... Feb 26 22:27:03 loe volumio[5800]: info: [1772141223082] Starting Upmpd Daemon Feb 26 22:27:03 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 26 22:27:03 loe volumio[5800]: info: Loading plugin "my_music"... Feb 26 22:27:03 loe volumio[5800]: info: Loading plugin "mpd"... Feb 26 22:27:03 loe sudo[5854]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:03 loe volumio[5800]: info: Loading plugin "upnp_browser"... Feb 26 22:27:03 loe volumio5-onboarding[2759]: time=2026-02-26T22:27:03.931+01:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.178.147:51706 @ 0x2cfeb70" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Feb 26 22:27:04 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 26 22:27:04 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:04 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:04 loe go-librespot[5877]: go-librespot daemon starting... Feb 26 22:27:04 loe ntpd[879]: PROTO: 94.198.159.16 unlink local addr 192.168.178.145 -> Feb 26 22:27:04 loe go-librespot[5878]: time="2026-02-26T22:27:04+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:27:04 loe go-librespot[5878]: time="2026-02-26T22:27:04+01:00" level=debug msg="app state loaded" Feb 26 22:27:04 loe go-librespot[5878]: time="2026-02-26T22:27:04+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:27:05 loe go-librespot[5878]: time="2026-02-26T22:27:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:27:05 loe go-librespot[5878]: time="2026-02-26T22:27:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:27:05 loe go-librespot[5878]: time="2026-02-26T22:27:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:27:05 loe go-librespot[5878]: time="2026-02-26T22:27:05+01:00" level=info msg="zeroconf server listening on port 44001" Feb 26 22:27:05 loe volumio5-onboarding[2759]: time=2026-02-26T22:27:05.328+01:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.178.147:51706 @ 0x2cfeb70" latency=-50.218634ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Feb 26 22:27:05 loe go-librespot[5878]: time="2026-02-26T22:27:05+01:00" level=debug msg="obtained new client token: AAA+qZR9f6vF9fA3toV9ibaYvDzP5UA601XsMTKPGdNpXfgJu5koik0s8XDx+fUzNXjwgIrmebnF4VZzRfcl+Dp5ikegNbXCiV8feRZlPxOEcNjSoeutOZHw4tRotYcDLfDvXUf4FCDNFnVLfFjhVDcDdjIOrufHIl2MdwM5VkleWggw4NJnH7AY7RUMILJB5DxI3oZWqOgaNvR69/ceJQH3rRf/9r7S719/CnJmqCYSYqZDmHFoAEByJQ==" Feb 26 22:27:05 loe go-librespot[5878]: time="2026-02-26T22:27:05+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:27:05 loe go-librespot[5878]: time="2026-02-26T22:27:05+01:00" level=debug msg="completed keyexchange" Feb 26 22:27:05 loe go-librespot[5878]: time="2026-02-26T22:27:05+01:00" level=debug msg="completed challenge" Feb 26 22:27:05 loe go-librespot[5878]: time="2026-02-26T22:27:05+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:27:05 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:27:05 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:27:06 loe volumio[5800]: info: Starting UPNP Browser Feb 26 22:27:06 loe volumio[5800]: info: Loading plugin "alarm-clock"... Feb 26 22:27:06 loe volumio[5800]: info: Loading plugin "airplay_emulation"... Feb 26 22:27:06 loe volumio[5800]: info: Starting Shairport Sync Feb 26 22:27:06 loe volumio[5800]: info: Loading plugin "last_100"... Feb 26 22:27:06 loe volumio[5800]: info: Loading plugin "webradio"... Feb 26 22:27:07 loe volumio[5800]: info: Loading plugin "i2s_dacs"... Feb 26 22:27:07 loe volumio[5800]: info: Loading plugin "volumiodiscovery"... Feb 26 22:27:07 loe volumio[5800]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 26 22:27:07 loe volumio[5800]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 26 22:27:07 loe node[5800]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 26 22:27:07 loe volumio[5800]: *** WARNING *** For more information see Feb 26 22:27:07 loe volumio[5800]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 26 22:27:07 loe volumio[5800]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 26 22:27:07 loe volumio[5800]: *** WARNING *** For more information see Feb 26 22:27:07 loe node[5800]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 26 22:27:07 loe node[5800]: *** WARNING *** For more information see Feb 26 22:27:07 loe node[5800]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 26 22:27:07 loe node[5800]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 26 22:27:07 loe node[5800]: *** WARNING *** For more information see Feb 26 22:27:07 loe volumio[5800]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 26 22:27:07 loe volumio[5800]: info: Discovery: Started advertising with name: Loe Feb 26 22:27:07 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 26 22:27:07 loe volumio[5800]: info: Loading plugin "spop"... Feb 26 22:27:08 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 26 22:27:08 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:08 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:08 loe go-librespot[5888]: go-librespot daemon starting... Feb 26 22:27:08 loe go-librespot[5889]: time="2026-02-26T22:27:08+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:27:08 loe go-librespot[5889]: time="2026-02-26T22:27:08+01:00" level=debug msg="app state loaded" Feb 26 22:27:08 loe go-librespot[5889]: time="2026-02-26T22:27:08+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:27:09 loe volumio[5800]: info: Loading plugin "outputs"... Feb 26 22:27:09 loe volumio[5800]: info: Loading plugin "albumart"... Feb 26 22:27:09 loe volumio5-onboarding[2759]: time=2026-02-26T22:27:09.152+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="read tcp 127.0.0.1:49250->127.0.0.1:3000: i/o timeout" Feb 26 22:27:09 loe volumio[5800]: info: Plugin example_plugin is not enabled Feb 26 22:27:09 loe volumio[5800]: info: Loading plugin "inputs"... Feb 26 22:27:09 loe volumio[5800]: info: Loading plugin "updater_comm"... Feb 26 22:27:09 loe go-librespot[5889]: time="2026-02-26T22:27:09+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 26 22:27:09 loe go-librespot[5889]: time="2026-02-26T22:27:09+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 26 22:27:09 loe go-librespot[5889]: time="2026-02-26T22:27:09+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 26 22:27:09 loe go-librespot[5889]: time="2026-02-26T22:27:09+01:00" level=info msg="zeroconf server listening on port 33367" Feb 26 22:27:09 loe volumio[5800]: info: Plugin mpdemulation is not enabled Feb 26 22:27:09 loe volumio[5800]: info: Loading plugin "rest_api"... Feb 26 22:27:09 loe volumio[5800]: info: Loading plugin "websocket"... Feb 26 22:27:09 loe volumio[5800]: info: Starting Socket.io Server version 1.7.4 Feb 26 22:27:09 loe go-librespot[5889]: time="2026-02-26T22:27:09+01:00" level=debug msg="obtained new client token: AACQkuIVQND+KThAzygDwmP2QfaFBIm0Po/XnlyLOC7esdxZV+QJ+Aw1Apf0HukGNhKDTY9+k4ns950Jn35yPlI1unF8UrQN0hSW72Djg97crx6PfFXZ8GxETVy3UVjMxO3OWyNTbFjvL/X/KLPSf8mkVGXyEWim4/zdYV2RkxheIe/965kPbHpQAhWXsJIVUSz8RKv/7K2X1GlqtsNkTzkt7zLmAzAbDUy0FhwwewFoBWyXxRnUPztmJA==" Feb 26 22:27:09 loe volumio[5800]: info: Loading i18n strings for locale nl Feb 26 22:27:09 loe volumio[5800]: Updating browse sources language Feb 26 22:27:09 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 22:27:09 loe go-librespot[5889]: time="2026-02-26T22:27:09+01: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" Feb 26 22:27:09 loe go-librespot[5889]: time="2026-02-26T22:27:09+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Feb 26 22:27:09 loe go-librespot[5889]: time="2026-02-26T22:27:09+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 26 22:27:09 loe go-librespot[5889]: time="2026-02-26T22:27:09+01:00" level=debug msg="completed keyexchange" Feb 26 22:27:09 loe go-librespot[5889]: time="2026-02-26T22:27:09+01:00" level=debug msg="completed challenge" Feb 26 22:27:09 loe go-librespot[5889]: time="2026-02-26T22:27:09+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:27:09 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:27:09 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:27:09 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 22:27:09 loe volumio[5800]: info: CoreCommandRouter::initPlayerControls Feb 26 22:27:09 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:09 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:09 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:09 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:09 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:09 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:09 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:09 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:09 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 22:27:09 loe volumio[5800]: Express server listening on port 3000 Feb 26 22:27:09 loe volumio[5800]: [Metrics] WebUI: 11s 642.47ms Feb 26 22:27:09 loe volumio[5800]: info: CoreStateMachine::resetVolumioState Feb 26 22:27:09 loe volumio[5800]: info: CoreStateMachine::getcurrentVolume Feb 26 22:27:09 loe volumio[5800]: info: CoreCommandRouter::volumioRetrievevolume Feb 26 22:27:09 loe volumio[5800]: info: Volumio Network Manager: Network status updated: 1 Feb 26 22:27:10 loe volumio[5896]: Forking 3 albumart workers Feb 26 22:27:10 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:10 loe volumio[5800]: info: Reloading queue from file Feb 26 22:27:10 loe volumio[5800]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.79 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Feb 26 22:27:10 loe volumio[5800]: info: CoreStateMachine::setRepeat false single undefined Feb 26 22:27:10 loe volumio[5800]: info: CoreStateMachine::pushState Feb 26 22:27:10 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:10 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:27:10 loe volumio[5800]: info: CoreCommandRouter::volumioPushState Feb 26 22:27:10 loe volumio[5800]: info: CoreStateMachine::setRandom undefined Feb 26 22:27:10 loe volumio[5800]: info: CoreStateMachine::pushState Feb 26 22:27:10 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:10 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:27:10 loe volumio[5800]: info: CoreCommandRouter::volumioPushState Feb 26 22:27:10 loe volumio[5800]: info: Setting Device type: Raspberry PI Feb 26 22:27:10 loe volumio[5800]: info: Completed loading Core Plugins Feb 26 22:27:10 loe volumio[5800]: info: Preparing to generate the ALSA configuration file Feb 26 22:27:10 loe volumio[5800]: info: VolumeController:: Volume=33 Mute =false Feb 26 22:27:10 loe volumio[5800]: info: CoreStateMachine::pushState Feb 26 22:27:10 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:10 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:27:10 loe volumio[5800]: info: CoreCommandRouter::volumioPushState Feb 26 22:27:10 loe volumio[5800]: info: CoreStateMachine::updateTrackBlock Feb 26 22:27:10 loe volumio[5800]: info: CorePlayQueue::getTrackBlock Feb 26 22:27:10 loe volumio[5800]: info: CoreCommandRouter::volumioRetrievevolume Feb 26 22:27:10 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 22:27:10 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 22:27:10 loe volumio[5800]: info: Discovery: Getting this device information Feb 26 22:27:10 loe volumio[5800]: info: CoreCommandRouter::volumioGetState Feb 26 22:27:10 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:10 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 22:27:10 loe volumio[5800]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.79 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Feb 26 22:27:10 loe volumio[5800]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Feb 26 22:27:10 loe volumio[5800]: info: Discovery: adding 07fbb113-343c-4b34-af49-444dc3d8fb26 Feb 26 22:27:10 loe volumio[5800]: info: Discovery: Found device Loe Feb 26 22:27:10 loe volumio[5800]: info: CoreCommandRouter::volumioGetState Feb 26 22:27:10 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:10 loe volumio[5800]: verbose: New Socket.io Connection to 192.168.178.145:3000 from 192.168.178.147 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 3 Feb 26 22:27:10 loe volumio[5800]: info: VolumeController:: Volume=33 Mute =false Feb 26 22:27:10 loe volumio[5800]: info: CoreStateMachine::pushState Feb 26 22:27:10 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:10 loe volumio[5800]: info: CoreCommandRouter::volumioPushState Feb 26 22:27:10 loe volumio[5800]: info: Discovery: this is already registered, 07fbb113-343c-4b34-af49-444dc3d8fb26 Feb 26 22:27:10 loe volumio[5800]: info: Discovery: Found device Loe Feb 26 22:27:10 loe volumio[5800]: info: CoreCommandRouter::volumioGetState Feb 26 22:27:10 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:10 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 26 22:27:10 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 26 22:27:11 loe volumio[5800]: info: Asound.conf file written Feb 26 22:27:11 loe sudo[5953]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Feb 26 22:27:11 loe sudo[5953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:11 loe sudo[5953]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:11 loe volumio[5800]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Feb 26 22:27:11 loe volumio[5800]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Feb 26 22:27:11 loe volumio[5800]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Feb 26 22:27:11 loe volumio[5800]: No state is present for card vc4hdmi Feb 26 22:27:11 loe volumio[5800]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Feb 26 22:27:11 loe volumio[5800]: Found hardware: "vc4-hdmi" "" "" "" "" Feb 26 22:27:11 loe volumio[5800]: Hardware is initialized using a generic method Feb 26 22:27:11 loe volumio[5800]: No state is present for card vc4hdmi Feb 26 22:27:11 loe volumio[5800]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2 Feb 26 22:27:11 loe volumio[5800]: info: Output device has changed, restarting MPD Feb 26 22:27:11 loe volumio[5800]: info: Output device has changed, restarting Shairport Sync Feb 26 22:27:11 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:11 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:11 loe sudo[5959]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 26 22:27:11 loe sudo[5959]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:11 loe sudo[5961]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 26 22:27:11 loe sudo[5961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:11 loe sudo[5959]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:11 loe volumio[5800]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 26 22:27:11 loe volumio[5800]: info: ___________ START PLUGINS ___________ Feb 26 22:27:11 loe volumio[5800]: info: ControllerMpd::onStart: Initializing MPD Feb 26 22:27:11 loe volumio[5800]: info: Creating MPD Configuration file Feb 26 22:27:11 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 22:27:11 loe volumio[5800]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 22:27:11 loe volumio[5800]: info: [1772141231506] CoreMusicLibrary::Adding element Media Servers Feb 26 22:27:11 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 22:27:11 loe sudo[5969]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Feb 26 22:27:11 loe systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 26 22:27:11 loe sudo[5969]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:11 loe upmpdcli[1389]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Feb 26 22:27:11 loe sudo[5972]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 26 22:27:11 loe sudo[5972]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:11 loe volumio[5800]: info: UPNP Browser: Client initialized successfully Feb 26 22:27:11 loe sudo[5973]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 26 22:27:11 loe sudo[5972]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:11 loe sudo[5973]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:11 loe systemd[1]: mpd.service: Deactivated successfully. Feb 26 22:27:11 loe systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 26 22:27:11 loe systemd[1]: mpd.service: Consumed 14.223s CPU time. Feb 26 22:27:11 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:11 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:11 loe systemd[1]: mpd.socket: Deactivated successfully. Feb 26 22:27:11 loe systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 26 22:27:11 loe systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 26 22:27:11 loe volumio[5800]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 26 22:27:11 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:11 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:11 loe systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 26 22:27:11 loe systemd[1]: Starting mpd.service - Music Player Daemon... Feb 26 22:27:11 loe systemd[1]: mpd.service: Deactivated successfully. Feb 26 22:27:11 loe systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 26 22:27:11 loe systemd[1]: mpd.socket: Deactivated successfully. Feb 26 22:27:11 loe systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 26 22:27:11 loe systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 26 22:27:11 loe sudo[5969]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:11 loe volumio[5800]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 26 22:27:11 loe volumio[5800]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 22:27:11 loe volumio[5800]: info: [1772141231939] CoreMusicLibrary::Adding element Last_100 Feb 26 22:27:11 loe systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 26 22:27:11 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 22:27:11 loe systemd[1]: Starting mpd.service - Music Player Daemon... Feb 26 22:27:11 loe volumio[5800]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 22:27:11 loe volumio[5800]: info: [1772141231974] CoreMusicLibrary::Adding element Webradio Feb 26 22:27:11 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 22:27:12 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 26 22:27:12 loe volumio[5800]: info: Initializing BBC Radios Feb 26 22:27:12 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 26 22:27:12 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:12 loe volumio[5800]: info: Creating Spotify config file Feb 26 22:27:12 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:12 loe sudo[5988]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 26 22:27:12 loe sudo[5988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 26 22:27:12 loe sudo[5988]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:12 loe volumio-remote-updater[708]: [2026-02-26 22:27:12] [connect] Successful connection Feb 26 22:27:12 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 26 22:27:13 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:13 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:13 loe go-librespot[6018]: go-librespot daemon starting... Feb 26 22:27:13 loe go-librespot[6019]: time="2026-02-26T22:27:13+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:27:13 loe volumio[5913]: Starting albumart workers Feb 26 22:27:13 loe volumio[5800]: info: Volumio Calling Home Feb 26 22:27:13 loe volumio[5914]: Starting albumart workers Feb 26 22:27:13 loe volumio[5916]: Starting albumart workers Feb 26 22:27:13 loe go-librespot[6019]: time="2026-02-26T22:27:13+01:00" level=info msg="zeroconf server listening on port 33267" Feb 26 22:27:13 loe volumio5-onboarding[2759]: time=2026-02-26T22:27:13.917+01:00 level=ERROR msg="failed to update discovery on Wi-Fi info change" error="failed to get system info: could not get system info: context deadline exceeded" Feb 26 22:27:14 loe sudo[6031]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 26 22:27:14 loe sudo[6031]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:14 loe sudo[6033]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 26 22:27:14 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 26 22:27:14 loe sudo[6033]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:14 loe sudo[6033]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:14 loe sudo[6031]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:14 loe volumio[5800]: info: MPD Permissions set Feb 26 22:27:14 loe volumio[5800]: info: MPD Permissions set Feb 26 22:27:15 loe volumio[5800]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Feb 26 22:27:15 loe volumio[5800]: info: Volumio called home Feb 26 22:27:15 loe volumio[5800]: info: Spotify config file written Feb 26 22:27:15 loe sudo[6037]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 26 22:27:15 loe sudo[6037]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:15 loe systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 26 22:27:15 loe systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 26 22:27:15 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:15 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:15 loe go-librespot[6040]: go-librespot daemon starting... Feb 26 22:27:15 loe sudo[6037]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:15 loe go-librespot[6047]: time="2026-02-26T22:27:15+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:27:15 loe go-librespot[6047]: time="2026-02-26T22:27:15+01:00" level=debug msg="app state loaded" Feb 26 22:27:15 loe go-librespot[6047]: time="2026-02-26T22:27:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:27:15 loe volumio-remote-updater[708]: [2026-02-26 22:27:15] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772141232 101 Feb 26 22:27:15 loe volumio[5800]: 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: 3 Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:15 loe volumio[5800]: info: No need to fix Spotify hosts Feb 26 22:27:16 loe go-librespot[6047]: time="2026-02-26T22:27:16+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 26 22:27:16 loe go-librespot[6047]: time="2026-02-26T22:27:16+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 26 22:27:16 loe go-librespot[6047]: time="2026-02-26T22:27:16+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 26 22:27:16 loe go-librespot[6047]: time="2026-02-26T22:27:16+01:00" level=info msg="zeroconf server listening on port 43103" Feb 26 22:27:16 loe volumio[5800]: info: CoreCommandRouter::volumioGetVisibleSources Feb 26 22:27:16 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 22:27:16 loe volumio[5800]: info: CoreCommandRouter::volumioGetState Feb 26 22:27:16 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:16 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 26 22:27:16 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 26 22:27:16 loe volumio[5800]: info: Received Get System Info Feb 26 22:27:16 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 22:27:16 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 22:27:16 loe volumio[5800]: info: Discovery: Getting this device information Feb 26 22:27:16 loe volumio[5800]: info: CoreCommandRouter::volumioGetState Feb 26 22:27:16 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:16 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 22:27:16 loe volumio[5800]: info: CoreCommandRouter::volumioGetState Feb 26 22:27:16 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:16 loe go-librespot[6047]: time="2026-02-26T22:27:16+01:00" level=debug msg="obtained new client token: AABzrc7zwJQTDSTBsl7eE9+ZWXzLGW5wjEWNrV4juYT5J7l5t8I3iVnCk+MnTxVIE2E+OUz3Y5vEQpqwWjCnk4xySlVIbYXerYhEg9+WwBdfQrxWKUG/L+KZcj0F8q1j3WEux0vAtYmeieS6dco091dqM7nKR2CFDQx3cJYVAFJM9tkwjbuCVSlG9ilSohMVdXhYnjkJa9R9Kyp2xwhep9SsqBksJ5HMcCHQTLXzoI+/glnxMeIPGVc=" Feb 26 22:27:16 loe volumio[5800]: info: Listing playlists Feb 26 22:27:16 loe volumio[5800]: info: CoreCommandRouter::volumioGetQueue Feb 26 22:27:16 loe volumio[5800]: info: CoreStateMachine::getQueue Feb 26 22:27:16 loe volumio[5800]: info: CorePlayQueue::getQueue Feb 26 22:27:16 loe go-librespot[6047]: time="2026-02-26T22:27:16+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:27:16 loe volumio[5800]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Feb 26 22:27:16 loe go-librespot[6047]: time="2026-02-26T22:27:16+01:00" level=debug msg="completed keyexchange" Feb 26 22:27:16 loe go-librespot[6047]: time="2026-02-26T22:27:16+01:00" level=debug msg="completed challenge" Feb 26 22:27:16 loe go-librespot[6047]: time="2026-02-26T22:27:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:27:16 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:27:16 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:27:16 loe volumio[5800]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Feb 26 22:27:16 loe volumio[5800]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 26 22:27:16 loe volumio[5800]: info: Starting Shairport Sync Feb 26 22:27:16 loe volumio[5800]: info: Starting Shairport Sync Feb 26 22:27:16 loe volumio[5800]: info: Starting Shairport Sync Feb 26 22:27:16 loe sudo[6079]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 26 22:27:16 loe sudo[6079]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:16 loe sudo[6081]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 26 22:27:16 loe sudo[6081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:16 loe volumio[5800]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Feb 26 22:27:16 loe sudo[6083]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 26 22:27:16 loe sudo[6083]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:16 loe sudo[6088]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 26 22:27:16 loe sudo[6088]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:16 loe systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 26 22:27:16 loe systemd[1]: shairport-sync.service: Deactivated successfully. Feb 26 22:27:16 loe systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 26 22:27:16 loe systemd[1]: shairport-sync.service: Consumed 6.006s CPU time. Feb 26 22:27:16 loe systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 26 22:27:16 loe sudo[6083]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:16 loe sudo[6079]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:16 loe sudo[6092]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 26 22:27:16 loe sudo[6088]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:16 loe sudo[6081]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:16 loe sudo[6092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:17 loe sudo[6092]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:17 loe volumio[5800]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Feb 26 22:27:17 loe sudo[6094]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 26 22:27:17 loe sudo[6094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:17 loe sudo[6094]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:17 loe volumio[5800]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Feb 26 22:27:17 loe volumio[5800]: info: Shairport-Sync Started Feb 26 22:27:17 loe volumio[5800]: Error adding Membership: Error: addMembership EINVAL Feb 26 22:27:17 loe volumio[5800]: info: Upmpdcli Daemon Started Feb 26 22:27:17 loe volumio[5800]: info: Shairport-Sync Started Feb 26 22:27:17 loe volumio[5800]: info: Shairport-Sync Started Feb 26 22:27:17 loe volumio[5800]: info: CoreCommandRouter::volumioGetState Feb 26 22:27:17 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:17 loe volumio[5800]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.79 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Feb 26 22:27:17 loe sudo[6112]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 26 22:27:17 loe sudo[6112]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:17 loe sudo[6114]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 26 22:27:17 loe sudo[6114]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:17 loe sudo[6112]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:17 loe sudo[6114]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:17 loe volumio[5800]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.79 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Feb 26 22:27:17 loe upmpdcli[1389]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Feb 26 22:27:17 loe upmpdcli[1389]: :2:../src/mpdcli.cxx:396::MPDCli::updStatus: connection failed Feb 26 22:27:17 loe upmpdcli[1389]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Feb 26 22:27:17 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 26 22:27:17 loe volumio[5800]: info: CoreCommandRouter::volumioGetVisibleSources Feb 26 22:27:17 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 22:27:17 loe volumio[5800]: info: CoreCommandRouter::volumioGetState Feb 26 22:27:17 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:17 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 26 22:27:17 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 26 22:27:17 loe volumio[5800]: info: Received Get System Info Feb 26 22:27:17 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 22:27:17 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 22:27:17 loe volumio[5800]: info: Discovery: Getting this device information Feb 26 22:27:17 loe volumio[5800]: info: CoreCommandRouter::volumioGetState Feb 26 22:27:17 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:17 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 22:27:17 loe volumio[5800]: info: CoreCommandRouter::volumioGetState Feb 26 22:27:17 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:17 loe volumio[5800]: info: Listing playlists Feb 26 22:27:17 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 26 22:27:17 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 26 22:27:19 loe mpd[6003]: 2026-02-26T22:27:19 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 26 22:27:19 loe systemd[1]: Started mpd.service - Music Player Daemon. Feb 26 22:27:19 loe sudo[5973]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:19 loe sudo[5961]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:19 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Feb 26 22:27:19 loe volumio[5800]: info: Completed starting Core Plugins Feb 26 22:27:19 loe volumio[5800]: info: ------------------------------------------- Feb 26 22:27:19 loe volumio[5800]: info: ----- MyVolumio plugins startup ---- Feb 26 22:27:19 loe volumio[5800]: info: ------------------------------------------- Feb 26 22:27:19 loe volumio[5800]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 26 22:27:19 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 26 22:27:19 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:19 loe volumio[5800]: error: MPD error: The expression evaluated to a falsy value: Feb 26 22:27:19 loe volumio[5800]: assert.ok(self.idling) Feb 26 22:27:19 loe volumio[5800]: error: The expression evaluated to a falsy value: Feb 26 22:27:19 loe volumio[5800]: assert.ok(self.idling) Feb 26 22:27:19 loe volumio[5800]: info: go-librespot daemon successfully initialized Feb 26 22:27:19 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 26 22:27:19 loe volumio[5800]: info: Received Get System Info Feb 26 22:27:19 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 22:27:19 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 22:27:19 loe volumio[5800]: info: Discovery: Getting this device information Feb 26 22:27:19 loe volumio[5800]: info: CoreCommandRouter::volumioGetState Feb 26 22:27:19 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:19 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 22:27:19 loe volumio[5800]: info: MPD running with PID6003 Feb 26 22:27:19 loe volumio[5800]: ,establishing connection Feb 26 22:27:19 loe volumio[5800]: error: updateQueue error: null Feb 26 22:27:19 loe volumio[5800]: error: updateQueue error: null Feb 26 22:27:19 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:19 loe go-librespot[6121]: go-librespot daemon starting... Feb 26 22:27:19 loe upmpdcli[1389]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Feb 26 22:27:19 loe go-librespot[6122]: time="2026-02-26T22:27:19+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:27:19 loe go-librespot[6122]: time="2026-02-26T22:27:19+01:00" level=debug msg="app state loaded" Feb 26 22:27:19 loe go-librespot[6122]: time="2026-02-26T22:27:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:27:19 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Feb 26 22:27:19 loe go-librespot[6122]: time="2026-02-26T22:27:19+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 26 22:27:19 loe go-librespot[6122]: time="2026-02-26T22:27:19+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 26 22:27:19 loe go-librespot[6122]: time="2026-02-26T22:27:19+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 26 22:27:20 loe go-librespot[6122]: time="2026-02-26T22:27:20+01:00" level=info msg="zeroconf server listening on port 46629" Feb 26 22:27:20 loe go-librespot[6122]: time="2026-02-26T22:27:20+01:00" level=debug msg="obtained new client token: AADk/nz7T0QvJwj5rKzkHeUmyWggqQXeLcfVEXzbTqPjwV4+wHibDacymQG0EfvRckZcFN7pRWlV0GcjDvouNs9Ogso6jjPO4IRgSTH4EMxMwWpOdCHI7jmKkAx+aXIRfGIi7mM9fednONhYiSxiowNaX7x5i+ipDI+5a/pvbzeXRfHv+lpH8TLD5jUADrtEC5tnzMcKiYw0OVxM+Dg8SLDiagaPmyUCMHc5g0can5nFCBYUMQTyB50=" Feb 26 22:27:20 loe go-librespot[6122]: time="2026-02-26T22:27:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:27:20 loe go-librespot[6122]: time="2026-02-26T22:27:20+01:00" level=debug msg="completed keyexchange" Feb 26 22:27:20 loe go-librespot[6122]: time="2026-02-26T22:27:20+01:00" level=debug msg="completed challenge" Feb 26 22:27:20 loe go-librespot[6122]: time="2026-02-26T22:27:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:27:20 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:27:20 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:27:20 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 26 22:27:20 loe volumio[5800]: info: Received Get System Info Feb 26 22:27:20 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 22:27:20 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 22:27:20 loe volumio[5800]: info: Discovery: Getting this device information Feb 26 22:27:20 loe volumio[5800]: info: CoreCommandRouter::volumioGetState Feb 26 22:27:20 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:20 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 22:27:21 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Feb 26 22:27:22 loe volumio[5800]: info: Initializing connection to go-librespot Websocket Feb 26 22:27:22 loe volumio[5800]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 22:27:23 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 26 22:27:23 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:23 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:23 loe go-librespot[6143]: go-librespot daemon starting... Feb 26 22:27:23 loe go-librespot[6144]: time="2026-02-26T22:27:23+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:27:23 loe go-librespot[6144]: time="2026-02-26T22:27:23+01:00" level=debug msg="app state loaded" Feb 26 22:27:23 loe go-librespot[6144]: time="2026-02-26T22:27:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:27:23 loe go-librespot[6144]: time="2026-02-26T22:27:23+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 26 22:27:23 loe go-librespot[6144]: time="2026-02-26T22:27:23+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 26 22:27:23 loe go-librespot[6144]: time="2026-02-26T22:27:23+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 26 22:27:23 loe go-librespot[6144]: time="2026-02-26T22:27:23+01:00" level=info msg="zeroconf server listening on port 44939" Feb 26 22:27:24 loe go-librespot[6144]: time="2026-02-26T22:27:24+01:00" level=debug msg="obtained new client token: AADJINpX0VWp3sh94VoWgzb0rVed5eF6+JNHU2MRboEWJli+jT/sNSOxkpuQ+N6ZEGuG7CXITPNusfdrbtEWkj6lhdnSqpFr5cQMV8TJlZIyp+Kqwm1nXfzcWKf/F1e+c/hUuoTGBLY2oRUzBKT2b8fyd24n+wmzgEe/5BiL3h/bo7/sIV52Nouox+krsBXkjwNz5+EKmH+wNFtMhWZi+EWVOxveO3fKHK0Qxr0KkpQdLM8EUwkfg2E=" Feb 26 22:27:24 loe go-librespot[6144]: time="2026-02-26T22:27:24+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:27:24 loe go-librespot[6144]: time="2026-02-26T22:27:24+01:00" level=debug msg="completed keyexchange" Feb 26 22:27:24 loe go-librespot[6144]: time="2026-02-26T22:27:24+01:00" level=debug msg="completed challenge" Feb 26 22:27:24 loe go-librespot[6144]: time="2026-02-26T22:27:24+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:27:24 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:27:24 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:27:24 loe volumio[5800]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 26 22:27:25 loe volumio[5800]: info: Initializing connection to go-librespot Websocket Feb 26 22:27:25 loe volumio[5800]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 22:27:26 loe volumio[5800]: info: CoreCommandRouter::volumioPlay Feb 26 22:27:26 loe volumio[5800]: info: CoreStateMachine::play index undefined Feb 26 22:27:26 loe volumio[5800]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:27:26 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:26 loe volumio[5800]: info: CoreStateMachine::startPlaybackTimer Feb 26 22:27:26 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:26 loe volumio[5800]: info: CoreCommandRouter::volumioPlay Feb 26 22:27:26 loe volumio[5800]: info: CoreStateMachine::play index undefined Feb 26 22:27:26 loe volumio[5800]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:27:26 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:26 loe volumio[5800]: info: CoreStateMachine::startPlaybackTimer Feb 26 22:27:26 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:27 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 26 22:27:27 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:27 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Feb 26 22:27:27 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:27 loe go-librespot[6151]: go-librespot daemon starting... Feb 26 22:27:27 loe go-librespot[6152]: time="2026-02-26T22:27:27+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:27:27 loe go-librespot[6152]: time="2026-02-26T22:27:27+01:00" level=debug msg="app state loaded" Feb 26 22:27:27 loe go-librespot[6152]: time="2026-02-26T22:27:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 26 22:27:27 loe volumio[5800]: info: Adding plugin bluetooth to MyMusic Plugins Feb 26 22:27:27 loe volumio[5800]: info: Adding plugin multiroom to MyMusic Plugins Feb 26 22:27:27 loe volumio[5800]: info: Adding plugin metavolumio to MyMusic Plugins Feb 26 22:27:27 loe volumio[5800]: info: Adding plugin cd_controller to MyMusic Plugins Feb 26 22:27:27 loe volumio[5800]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 26 22:27:27 loe volumio[5800]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 26 22:27:27 loe volumio[5800]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 26 22:27:27 loe volumio[5800]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 26 22:27:27 loe go-librespot[6152]: time="2026-02-26T22:27:27+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:27:27 loe go-librespot[6152]: time="2026-02-26T22:27:27+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:27:27 loe go-librespot[6152]: time="2026-02-26T22:27:27+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:27:28 loe go-librespot[6152]: time="2026-02-26T22:27:28+01:00" level=info msg="zeroconf server listening on port 35323" Feb 26 22:27:28 loe go-librespot[6152]: time="2026-02-26T22:27:28+01:00" level=debug msg="obtained new client token: AADu2oSFBLybCHPki5wmMyrTnBYpVaA50lpo+gDXvaKhY15i+6lQzYgw2NEoS4VIs330G989x5V9M640o/wDottccu+9QHVMtf3ureziUnSkE24j+GmBKO8dW4/hVcfqCpwh1s3dez890LSkuUU9Ngx4McmKymQNBjHRgPZ6RCYakJtcGzLeNJsCbWmuzXcjMKQAtYqC9lRiFyYZVesIaPwp3uWTFqtrEAKfCNlJXglY8EVT2V2VpFE=" Feb 26 22:27:28 loe go-librespot[6152]: time="2026-02-26T22:27:28+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:27:28 loe go-librespot[6152]: time="2026-02-26T22:27:28+01:00" level=debug msg="completed keyexchange" Feb 26 22:27:28 loe go-librespot[6152]: time="2026-02-26T22:27:28+01:00" level=debug msg="completed challenge" Feb 26 22:27:28 loe go-librespot[6152]: time="2026-02-26T22:27:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:27:28 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:27:28 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:27:29 loe volumio[5800]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 26 22:27:29 loe volumio[5800]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 26 22:27:29 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:29 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:29 loe volumio[5800]: info: Starting MyVolumio Remote Streaming Endpoints Feb 26 22:27:29 loe volumio[5800]: info: MyVolumio login type: Token Feb 26 22:27:29 loe volumio[5800]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 26 22:27:29 loe volumio[5800]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 26 22:27:29 loe ntpd[879]: PROTO: 172.233.38.176 unlink local addr 192.168.178.145 -> Feb 26 22:27:31 loe volumio[5800]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 26 22:27:31 loe volumio[5800]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 26 22:27:31 loe volumio[5800]: info: Streaming services startup Feb 26 22:27:31 loe volumio[5800]: info: Starting Streaming Daemon Feb 26 22:27:31 loe sudo[6160]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 26 22:27:31 loe volumio[5800]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 26 22:27:31 loe sudo[6160]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:31 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 26 22:27:31 loe sudo[6160]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:31 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:31 loe volumio[5800]: info: Initializing connection to go-librespot Websocket Feb 26 22:27:31 loe volumio[5800]: info: CoreCommandRouter::volumioPlay Feb 26 22:27:31 loe volumio[5800]: info: CoreStateMachine::play index undefined Feb 26 22:27:31 loe volumio[5800]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:27:31 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:31 loe volumio[5800]: info: CoreStateMachine::startPlaybackTimer Feb 26 22:27:31 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:31 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:31 loe volumio[5800]: error: Cannot start Volumio Streaming Daemon Feb 26 22:27:31 loe volumio[5800]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 26 22:27:31 loe volumio[5800]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 26 22:27:31 loe go-librespot[6166]: go-librespot daemon starting... Feb 26 22:27:31 loe volumio[5800]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 22:27:31 loe go-librespot[6168]: time="2026-02-26T22:27:31+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:27:31 loe go-librespot[6168]: time="2026-02-26T22:27:31+01:00" level=debug msg="app state loaded" Feb 26 22:27:31 loe go-librespot[6168]: time="2026-02-26T22:27:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:27:31 loe go-librespot[6168]: time="2026-02-26T22:27:31+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:27:31 loe go-librespot[6168]: time="2026-02-26T22:27:31+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:27:31 loe go-librespot[6168]: time="2026-02-26T22:27:31+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:27:31 loe go-librespot[6168]: time="2026-02-26T22:27:31+01:00" level=info msg="zeroconf server listening on port 45625" Feb 26 22:27:32 loe go-librespot[6168]: time="2026-02-26T22:27:32+01:00" level=debug msg="obtained new client token: AAAYPJcEHnTA8FBpk00lC0Vg74nPBi0bOjZqlUo3HMboLHuT2/SSvhVjNHIXb0HXxaA8gSdBUcu6WaWjLQB0CYGVytJ5CmgO3KeiTaUpmmOTUzrPHXdf8ij5HZmLgXSj3qFGcNmrfhs9hRKgwzesJqoDeaS/uzy/KLvboJC74YRWBEmCuNhqsxT35IJ8DI5ndzZ/7545DARq3Adi8Gg5XbaphtmjMXA4qrAiLPwUAYrLtyl4s7wnRq4=" Feb 26 22:27:32 loe volumio[5800]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 26 22:27:32 loe go-librespot[6168]: time="2026-02-26T22:27:32+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:27:32 loe go-librespot[6168]: time="2026-02-26T22:27:32+01:00" level=debug msg="completed keyexchange" Feb 26 22:27:32 loe go-librespot[6168]: time="2026-02-26T22:27:32+01:00" level=debug msg="completed challenge" Feb 26 22:27:32 loe go-librespot[6168]: time="2026-02-26T22:27:32+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:27:32 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:27:32 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:27:32 loe volumio[5800]: info: MyVolumio token set successfully Feb 26 22:27:32 loe volumio[5800]: info: MYVOLUMIO: Adding device Feb 26 22:27:32 loe volumio[5800]: info: MYVOLUMIO: Evaluating Server Feb 26 22:27:33 loe volumio[5800]: info: MyVolumio Plan changed: premium Feb 26 22:27:33 loe volumio[5800]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Feb 26 22:27:33 loe volumio[5800]: info: Removing browser output: myVolumio user plan is not superstar Feb 26 22:27:33 loe volumio[5800]: info: Removing audio output: Feb 26 22:27:33 loe volumio[5800]: info: MYVOLUMIO: Adding device Feb 26 22:27:33 loe volumio[5800]: info: MYVOLUMIO: Evaluating Server Feb 26 22:27:33 loe volumio[5800]: info: Remote config written successfully Feb 26 22:27:33 loe volumio[5800]: info: Starting Tunnel 1 Feb 26 22:27:33 loe volumio[5800]: info: Starting Tunnel Connection Checker Feb 26 22:27:33 loe volumio[5800]: info: Completed starting MyVolumio Plugin Feb 26 22:27:33 loe volumio[5800]: info: MYVolumio Device enabled Feb 26 22:27:33 loe volumio[5800]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Feb 26 22:27:33 loe volumio[5800]: info: MyVolumio status changed Feb 26 22:27:33 loe volumio[5800]: info: Streaming services startup Feb 26 22:27:33 loe volumio[5800]: info: Starting Streaming Daemon Feb 26 22:27:33 loe volumio[5800]: info: Setting Geolocation for MyVolumio to eu8 Feb 26 22:27:33 loe sudo[6228]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 26 22:27:33 loe sudo[6228]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:33 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:33 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:33 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:33 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Feb 26 22:27:33 loe sudo[6228]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:33 loe volumio[5800]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Feb 26 22:27:34 loe volumio5-onboarding[2759]: time=2026-02-26T22:27:34.001+01:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.178.147:51706 @ 0x2cfeb70" latency=-51.224523ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Feb 26 22:27:34 loe volumio[5800]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Feb 26 22:27:34 loe volumio[5800]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Feb 26 22:27:35 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 26 22:27:35 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:35 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:35 loe go-librespot[6231]: go-librespot daemon starting... Feb 26 22:27:35 loe go-librespot[6232]: time="2026-02-26T22:27:35+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:27:35 loe go-librespot[6232]: time="2026-02-26T22:27:35+01:00" level=debug msg="app state loaded" Feb 26 22:27:35 loe go-librespot[6232]: time="2026-02-26T22:27:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:27:36 loe go-librespot[6232]: time="2026-02-26T22:27:36+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:27:36 loe go-librespot[6232]: time="2026-02-26T22:27:36+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:27:36 loe go-librespot[6232]: time="2026-02-26T22:27:36+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:27:36 loe go-librespot[6232]: time="2026-02-26T22:27:36+01:00" level=info msg="zeroconf server listening on port 40841" Feb 26 22:27:36 loe go-librespot[6232]: time="2026-02-26T22:27:36+01:00" level=debug msg="obtained new client token: AACi2nX6zw/g6t4EEQlktgkBJDhbitSh6ffs0JP0aAvRL3TgUXrGckfSj+qDNNeYPLa/FjLscp0eF2zcXVL/WlN8FP1GfKfbcajMkB5g9bdrmzz4mD3GSAF1wyFw5HM69ZQ5eDlUTXcujn75NpCQvrTA7wFS6WNQWeeNXBIFIaJ/rF05xf0WDHB6eCKTV1pP+LaTomLYLEYdjwWte6Y9846aTK1yHb/ZWbUmK0g1Gljra7w4cY1uVYA=" Feb 26 22:27:36 loe go-librespot[6232]: time="2026-02-26T22:27:36+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:27:36 loe go-librespot[6232]: time="2026-02-26T22:27:36+01:00" level=debug msg="completed keyexchange" Feb 26 22:27:36 loe go-librespot[6232]: time="2026-02-26T22:27:36+01:00" level=debug msg="completed challenge" Feb 26 22:27:36 loe go-librespot[6232]: time="2026-02-26T22:27:36+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:27:36 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:27:36 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:27:36 loe volumio[5800]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Feb 26 22:27:36 loe sudo[6243]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Feb 26 22:27:36 loe sudo[6243]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:36 loe sudo[6243]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:36 loe volumio[5800]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Feb 26 22:27:36 loe volumio[5800]: info: MRS: MultiRoom plugin initialized Feb 26 22:27:36 loe volumio[5800]: info: MRS: STOPPING SNAPCLIENT Feb 26 22:27:36 loe volumio[5800]: info: MRS: Snap server stop Feb 26 22:27:36 loe sudo[6260]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Feb 26 22:27:36 loe sudo[6260]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:36 loe sudo[6262]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Feb 26 22:27:36 loe sudo[6262]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:36 loe volumio[5800]: info: MRS: STOPPING volumioStreaming Feb 26 22:27:36 loe volumio[5800]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Feb 26 22:27:36 loe sudo[6267]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Feb 26 22:27:36 loe sudo[6267]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:36 loe sudo[6260]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:36 loe sudo[6268]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Feb 26 22:27:36 loe sudo[6268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:36 loe sudo[6267]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:36 loe volumio[5800]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Feb 26 22:27:36 loe volumio[5800]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Feb 26 22:27:36 loe volumio[5800]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Feb 26 22:27:36 loe sudo[6262]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:37 loe volumio[5800]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Feb 26 22:27:37 loe systemd[1]: Stopping volumioStreaming.service - VolumioStreamingService... Feb 26 22:27:37 loe systemd[1]: volumioStreaming.service: Killing process 5669 (ffmpeg) with signal SIGKILL. Feb 26 22:27:37 loe systemd[1]: volumioStreaming.service: Deactivated successfully. Feb 26 22:27:37 loe systemd[1]: Stopped volumioStreaming.service - VolumioStreamingService. Feb 26 22:27:37 loe systemd[1]: volumioStreaming.service: Consumed 1.523s CPU time. Feb 26 22:27:37 loe volumio[5800]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Feb 26 22:27:37 loe volumio[5800]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Feb 26 22:27:37 loe sudo[6268]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:37 loe volumio[5800]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Feb 26 22:27:37 loe volumio[5800]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Feb 26 22:27:37 loe volumio[5800]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Feb 26 22:27:37 loe volumio[5800]: info: Preparing to generate the ALSA configuration file Feb 26 22:27:37 loe volumio[5800]: info: Initializing connection to go-librespot Websocket Feb 26 22:27:37 loe volumio[5800]: info: Updating MyVolumio device info Feb 26 22:27:37 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:37 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:37 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:37 loe volumio[5800]: info: Setting Geolocation for MyVolumio to eu9 Feb 26 22:27:37 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:37 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:37 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:37 loe volumio[5800]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Feb 26 22:27:37 loe volumio[5800]: info: Reading ALSA contributions from plugins. Feb 26 22:27:37 loe volumio[5800]: info: Successfully Added MyVolumio device Feb 26 22:27:37 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 26 22:27:37 loe volumio[5800]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Feb 26 22:27:37 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Feb 26 22:27:37 loe volumio[5800]: info: Received Get System Version Feb 26 22:27:37 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 26 22:27:37 loe volumio[5800]: info: Received Get System Info Feb 26 22:27:37 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 22:27:37 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 22:27:37 loe volumio[5800]: info: Discovery: Getting this device information Feb 26 22:27:37 loe volumio[5800]: info: CoreCommandRouter::volumioGetState Feb 26 22:27:37 loe volumio[5800]: info: CorePlayQueue::getTrack 0 Feb 26 22:27:37 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 22:27:37 loe volumio[5800]: info: MRS: Removed streaming files Feb 26 22:27:37 loe volumio[5800]: info: MRS: volumioStreaming STOPPED Feb 26 22:27:37 loe volumio[5800]: info: MRS: SNAPSERVER STOPPED Feb 26 22:27:37 loe volumio[5800]: info: MRS: SNAPCLIENT STOPPED Feb 26 22:27:37 loe volumio[5800]: error: Cannot start Volumio Streaming Daemon Feb 26 22:27:37 loe volumio[5800]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 26 22:27:37 loe volumio[5800]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 26 22:27:37 loe volumio[5800]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 22:27:37 loe volumio[5800]: info: Asound.conf file written Feb 26 22:27:37 loe sudo[6275]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Feb 26 22:27:37 loe sudo[6275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:37 loe sudo[6275]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:37 loe volumio[5800]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Feb 26 22:27:37 loe volumio[5800]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Feb 26 22:27:37 loe volumio[5800]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Feb 26 22:27:37 loe volumio[5800]: No state is present for card vc4hdmi Feb 26 22:27:37 loe volumio[5800]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Feb 26 22:27:37 loe volumio[5800]: Found hardware: "vc4-hdmi" "" "" "" "" Feb 26 22:27:37 loe volumio[5800]: Hardware is initialized using a generic method Feb 26 22:27:37 loe volumio[5800]: No state is present for card vc4hdmi Feb 26 22:27:37 loe volumio[5800]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2 Feb 26 22:27:37 loe volumio[5800]: info: Output device has changed, restarting MPD Feb 26 22:27:37 loe volumio[5800]: info: Output device has changed, restarting Shairport Sync Feb 26 22:27:37 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:37 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:37 loe sudo[6281]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 26 22:27:37 loe sudo[6281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:37 loe sudo[6281]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:37 loe sudo[6283]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 26 22:27:37 loe sudo[6283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:37 loe volumio[5800]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 26 22:27:37 loe volumio[5800]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Feb 26 22:27:37 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:37 loe volumio[5800]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Feb 26 22:27:37 loe volumio[5800]: ------------------------------------ BT MESSAGE: [FUNC] onStart Feb 26 22:27:37 loe volumio[5800]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Feb 26 22:27:37 loe volumio[5800]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Feb 26 22:27:37 loe volumio[5800]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Feb 26 22:27:37 loe systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 26 22:27:37 loe upmpdcli[1389]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Feb 26 22:27:37 loe volumio[5800]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Feb 26 22:27:37 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Feb 26 22:27:37 loe volumio[5800]: info: MRS: Pushing multiroomSync output for this device Feb 26 22:27:37 loe volumio[5800]: info: MRS: Pushing multiroomSync output Feb 26 22:27:37 loe volumio[5800]: info: Adding audio output: Feb 26 22:27:37 loe volumio[5800]: info: Adding audio output: Feb 26 22:27:38 loe volumio[5800]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Feb 26 22:27:38 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:38 loe systemd[1]: mpd.service: Deactivated successfully. Feb 26 22:27:38 loe systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 26 22:27:38 loe systemd[1]: mpd.service: Consumed 6.905s CPU time. Feb 26 22:27:38 loe systemd[1]: mpd.socket: Deactivated successfully. Feb 26 22:27:38 loe systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 26 22:27:38 loe systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 26 22:27:38 loe volumio[5800]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Feb 26 22:27:38 loe volumio[5800]: info: Adding METAVOLUMIO REST API Endpoints Feb 26 22:27:38 loe volumio[5800]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Feb 26 22:27:38 loe volumio[5800]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Feb 26 22:27:38 loe volumio[5800]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Feb 26 22:27:38 loe volumio[5800]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Feb 26 22:27:38 loe volumio[5800]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Feb 26 22:27:38 loe volumio[5800]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Feb 26 22:27:38 loe volumio[5800]: info: Preparing CD Folders Feb 26 22:27:38 loe volumio[5800]: info: Adding CD REST API Endpoints Feb 26 22:27:38 loe volumio[5800]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Feb 26 22:27:38 loe volumio[5800]: info: Starting UDEV Watcher for CD Feb 26 22:27:38 loe volumio[5800]: info: Detecting CD presence with UDEV Feb 26 22:27:38 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Feb 26 22:27:38 loe bluetoothd[946]: Path / reserved for Adv Monitor app :1.110 Feb 26 22:27:38 loe systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 26 22:27:38 loe systemd[1]: Starting mpd.service - Music Player Daemon... Feb 26 22:27:38 loe bluetoothd[946]: Adv Monitor app :1.110 disconnected from D-Bus Feb 26 22:27:38 loe sudo[6300]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 26 22:27:38 loe sudo[6300]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 26 22:27:38 loe sudo[6300]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:39 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 26 22:27:39 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:39 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:39 loe go-librespot[6304]: go-librespot daemon starting... Feb 26 22:27:39 loe go-librespot[6305]: time="2026-02-26T22:27:39+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:27:39 loe go-librespot[6305]: time="2026-02-26T22:27:39+01:00" level=debug msg="app state loaded" Feb 26 22:27:39 loe go-librespot[6305]: time="2026-02-26T22:27:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:27:40 loe go-librespot[6305]: time="2026-02-26T22:27:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 26 22:27:40 loe go-librespot[6305]: time="2026-02-26T22:27:40+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 26 22:27:40 loe go-librespot[6305]: time="2026-02-26T22:27:40+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 26 22:27:40 loe go-librespot[6305]: time="2026-02-26T22:27:40+01:00" level=info msg="zeroconf server listening on port 45163" Feb 26 22:27:40 loe go-librespot[6305]: time="2026-02-26T22:27:40+01:00" level=debug msg="obtained new client token: AAD+qJbdy51N5bJJyPu+W8XPnpZJT6z2FFAOvLjBXV9/FCXDm979ZV0bNeEOOyRfpTxRAv3HMA72UrYyJxU9irt+3lrEZM6MD6jJeSG0CRtrXwgFauj6vUaDjHuV6IJj7cKDgXn4MuiSWkMIxdZAcEgxTRUq6pVShkmWMvH2h4wYox/ApF9eMzamTLZ5lmOA01nGJIufA9+rSe20CE+ajD/qca9fw9KdLIHLcB0LSz7zPJvO79RbZ+s=" Feb 26 22:27:40 loe go-librespot[6305]: time="2026-02-26T22:27:40+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:27:40 loe go-librespot[6305]: time="2026-02-26T22:27:40+01:00" level=debug msg="completed keyexchange" Feb 26 22:27:40 loe go-librespot[6305]: time="2026-02-26T22:27:40+01:00" level=debug msg="completed challenge" Feb 26 22:27:40 loe go-librespot[6305]: time="2026-02-26T22:27:40+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:27:40 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:27:40 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:27:43 loe volumio[5800]: warn: [cd-plugin] cdspeedctl: device or media not ready Feb 26 22:27:43 loe volumio[5800]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Feb 26 22:27:43 loe volumio[5800]: info: Adding inputs REST Endpoints Feb 26 22:27:43 loe volumio[5800]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Feb 26 22:27:43 loe volumio[5800]: info: Scanning Audio Inputs Feb 26 22:27:43 loe volumio[5800]: info: Checking against Known Cards name Feb 26 22:27:43 loe volumio[5800]: info: Adding Server instance for streaming Feb 26 22:27:43 loe volumio[5800]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Feb 26 22:27:43 loe volumio[5800]: info: Adding HIGHRESAUDIO REST API Endpoints Feb 26 22:27:43 loe volumio[5800]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Feb 26 22:27:43 loe volumio[5800]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Feb 26 22:27:43 loe volumio[5800]: info: Refreshing TIDAL token Feb 26 22:27:43 loe volumio[5800]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Feb 26 22:27:43 loe volumio[5800]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Feb 26 22:27:43 loe volumio[5800]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Feb 26 22:27:43 loe volumio[5800]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Feb 26 22:27:43 loe volumio[5800]: info: QobuzConnect: Starting Qobuz Connect socket and service Feb 26 22:27:43 loe sudo[6330]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Feb 26 22:27:43 loe sudo[6330]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:43 loe volumio[5800]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Feb 26 22:27:43 loe volumio[5800]: info: Stopping AccessToken refresher cron for QOBUZ Feb 26 22:27:43 loe sudo[6337]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Feb 26 22:27:43 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 26 22:27:43 loe sudo[6337]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:43 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:43 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:43 loe go-librespot[6339]: go-librespot daemon starting... Feb 26 22:27:43 loe systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Feb 26 22:27:43 loe volumio[5800]: info: AccessToken refresher cron started for QOBUZ Feb 26 22:27:43 loe volumio[5800]: info: Adding QOBUZ REST API Endpoints Feb 26 22:27:43 loe systemd[1]: vtcs.service: Killing process 4484 (vtcs) with signal SIGKILL. Feb 26 22:27:43 loe systemd[1]: vtcs.service: Deactivated successfully. Feb 26 22:27:43 loe systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Feb 26 22:27:43 loe systemd[1]: vtcs.service: Consumed 1.096s CPU time. Feb 26 22:27:43 loe go-librespot[6340]: time="2026-02-26T22:27:43+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:27:43 loe go-librespot[6340]: time="2026-02-26T22:27:43+01:00" level=debug msg="app state loaded" Feb 26 22:27:43 loe go-librespot[6340]: time="2026-02-26T22:27:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:27:43 loe volumio[5800]: info: MRS: Getting audio outputs on start Feb 26 22:27:43 loe volumio[5800]: info: MRS: Requesting all other devices output Feb 26 22:27:43 loe volumio[5800]: info: Updating MyVolumio device info Feb 26 22:27:43 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:43 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:43 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:43 loe sudo[6330]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:43 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 26 22:27:43 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:43 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 26 22:27:43 loe sudo[6337]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:43 loe volumio[5800]: info: Initializing connection to go-librespot Websocket Feb 26 22:27:43 loe volumio[5800]: info: Successfully Updated MyVolumio device Feb 26 22:27:43 loe mpd[6303]: 2026-02-26T22:27:43 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 26 22:27:43 loe sudo[6350]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Feb 26 22:27:43 loe sudo[6350]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:43 loe upmpdcli[1389]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Feb 26 22:27:43 loe systemd[1]: Started mpd.service - Music Player Daemon. Feb 26 22:27:43 loe sudo[6283]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:43 loe upmpdcli[1389]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Feb 26 22:27:43 loe systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Feb 26 22:27:43 loe qobuz-connect[4451]: 20260226 22:27:43.833 [4451.4451] INFO SampleApp: Stopping Local configuration server Feb 26 22:27:43 loe volumio[5800]: info: Successfully Added MyVolumio device Feb 26 22:27:43 loe volumio[5800]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Feb 26 22:27:43 loe volumio[5800]: info: MPD Permissions set Feb 26 22:27:43 loe sudo[6356]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Feb 26 22:27:43 loe sudo[6356]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:44 loe go-librespot[6340]: time="2026-02-26T22:27:44+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:27:44 loe go-librespot[6340]: time="2026-02-26T22:27:44+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:27:44 loe go-librespot[6340]: time="2026-02-26T22:27:44+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:27:44 loe sudo[6356]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:44 loe go-librespot[6340]: time="2026-02-26T22:27:44+01:00" level=info msg="zeroconf server listening on port 41775" Feb 26 22:27:44 loe go-librespot[6340]: time="2026-02-26T22:27:44+01:00" level=debug msg="new websocket client" Feb 26 22:27:44 loe go-librespot[6340]: time="2026-02-26T22:27:44+01:00" level=debug msg="obtained new client token: AADVueDmnv8z0MML8gvRZ/ThJKkSE2lMbxud1jvCtYZXbJ7vbcBhWtzydR7NneDGe3KV+1pJHANC6r1oODk2Oqf3OnZEZEg55ntWkUkxQY7zJo5pPceiJtmXazXHVv1Ragve669+qferUp6fkNnPD2dIFoNCsJ3dX0lb4asr3UmfeVQwOpyqLnwbsuSKecN06BGy9/LxyvqYbgfK+zuIpU/bYmYId9C+LbDO9DuOYGGLYBUk8d9QQZI=" Feb 26 22:27:44 loe volumio[5800]: ------------------------------------ BT MESSAGE: [_watchMediaPlayer] Binding activePlayer for path: /org/bluez/hci0/dev_C0_D5_E2_9C_B7_BA/avrcp/player0 Feb 26 22:27:44 loe volumio[5800]: ------------------------------------ BT MESSAGE: activePlayer bound: /org/bluez/hci0/dev_C0_D5_E2_9C_B7_BA/avrcp/player0 Feb 26 22:27:44 loe go-librespot[6340]: time="2026-02-26T22:27:44+01: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" Feb 26 22:27:44 loe volumio[5800]: info: Connection to go-librespot Websocket established Feb 26 22:27:44 loe volumio[5800]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Feb 26 22:27:44 loe volumio[5800]: info: CoreCommandRouter::volumioStop Feb 26 22:27:44 loe volumio[5800]: info: CoreStateMachine::stop Feb 26 22:27:44 loe volumio[5800]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:27:44 loe go-librespot[6340]: time="2026-02-26T22:27:44+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Feb 26 22:27:44 loe volumio[5800]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Feb 26 22:27:44 loe volumio[5800]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:27:44 loe go-librespot[6340]: time="2026-02-26T22:27:44+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 26 22:27:44 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:44 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:44 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:44 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:44 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:44 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:44 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:44 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:44 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:27:44 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:27:44 loe go-librespot[6340]: time="2026-02-26T22:27:44+01:00" level=debug msg="completed keyexchange" Feb 26 22:27:44 loe go-librespot[6340]: time="2026-02-26T22:27:44+01:00" level=debug msg="completed challenge" Feb 26 22:27:44 loe go-librespot[6340]: time="2026-02-26T22:27:44+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:27:44 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:27:44 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:27:44 loe volumio[5800]: info: Successfully Updated MyVolumio device Feb 26 22:27:44 loe volumio[5800]: error: updateQueue error: null Feb 26 22:27:44 loe volumio[5800]: error: Hi Res Audio Failed Login: [object Object] Feb 26 22:27:44 loe volumio-remote-updater[708]: Test mode disabled Feb 26 22:27:44 loe volumio-remote-updater[708]: Alpha mode disabled Feb 26 22:27:44 loe volumio-remote-updater[708]: Alpha legacy test mode disabled Feb 26 22:27:44 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 26 22:27:44 loe volumio[5800]: info: Connection to go-librespot Websocket closed Feb 26 22:27:44 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 26 22:27:44 loe volumio[5800]: info: Access Token successfully retrieved Feb 26 22:27:44 loe sudo[6373]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Feb 26 22:27:44 loe sudo[6373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:44 loe volumio[5800]: info: Starting Shairport Sync Feb 26 22:27:44 loe volumio[5800]: info: MRS: Found cast device: Chromecast-84d0dcfc86c31e08fb7722859cd1fe00 Feb 26 22:27:44 loe volumio[5800]: info: Adding audio output: Feb 26 22:27:44 loe volumio[5800]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 26 22:27:44 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 26 22:27:44 loe sudo[6376]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 26 22:27:44 loe autossh[4432]: received signal to exit (15) Feb 26 22:27:44 loe systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Feb 26 22:27:44 loe sudo[6376]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:44 loe systemd[1]: sshtunnel.service: Deactivated successfully. Feb 26 22:27:44 loe systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Feb 26 22:27:45 loe systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Feb 26 22:27:45 loe volumio[5800]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Feb 26 22:27:45 loe sudo[6373]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:45 loe autossh[6380]: port set to 0, monitoring disabled Feb 26 22:27:45 loe autossh[6380]: starting ssh (count 1) Feb 26 22:27:45 loe autossh[6380]: ssh child pid is 6383 Feb 26 22:27:45 loe volumio[5800]: info: Remote SSH Started Feb 26 22:27:45 loe systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 26 22:27:45 loe systemd[1]: shairport-sync.service: Deactivated successfully. Feb 26 22:27:45 loe systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 26 22:27:45 loe systemd[1]: shairport-sync.service: Consumed 2.013s CPU time. Feb 26 22:27:45 loe systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 26 22:27:45 loe sudo[6376]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:45 loe volumiossh-tunnel[6383]: Warning: Permanently added '[eu9.myvolumio.org]:2222' (RSA) to the list of known hosts. Feb 26 22:27:45 loe systemd[1]: qobuz-connect.service: Deactivated successfully. Feb 26 22:27:45 loe systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Feb 26 22:27:45 loe volumio[5800]: info: Successfully retrieved User Session From TIDAL Feb 26 22:27:45 loe systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Feb 26 22:27:45 loe volumio[5800]: info: Shairport-Sync Started Feb 26 22:27:45 loe sudo[6350]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:45 loe sudo[6401]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 26 22:27:45 loe sudo[6401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:45 loe sudo[6401]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:45 loe sudo[6403]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 26 22:27:45 loe sudo[6403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:45 loe sudo[6403]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:45 loe volumio[5800]: info: Successfully retrieved User Subscription From TIDAL Feb 26 22:27:45 loe volumio[5800]: info: Adding TIDAL to Browse Sources Feb 26 22:27:45 loe volumio[5800]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 22:27:45 loe volumio[5800]: info: [1772141265908] CoreMusicLibrary::Adding element TIDAL Feb 26 22:27:45 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 22:27:45 loe volumio[5800]: Cannot find translation for source TIDAL Feb 26 22:27:45 loe volumio[5800]: info: Adding TIDAL REST API Endpoints Feb 26 22:27:45 loe volumio[5800]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Feb 26 22:27:46 loe volumio[5800]: info: Executing endpoint qc_getconfig Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Feb 26 22:27:46 loe qobuz-connect[6399]: 20260226 22:27:46.101 [6399.6399] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Feb 26 22:27:46 loe qobuz-connect[6399]: 20260226 22:27:46.114 [6399.6399] INFO VolumeManager: [0x49c408]: Setting new playback volume: 75 Feb 26 22:27:46 loe qobuz-connect[6399]: 20260226 22:27:46.114 [6399.6399] INFO VolumeManager: [0x49c408]: Setting new mute state: 0 Feb 26 22:27:46 loe qobuz-connect[6399]: 20260226 22:27:46.114 [6399.6399] INFO QobuzConnect: [0x49cdd8]: Client initialized! Feb 26 22:27:46 loe qobuz-connect[6399]: 20260226 22:27:46.114 [6399.6399] INFO SampleApp: Starting Avahi advertising, name: Loe, service name: _qobuz-connect._tcp Feb 26 22:27:46 loe volumio[5800]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Feb 26 22:27:46 loe volumio[5800]: info: QobuzConnect: QOBUZ Connect daemon connected Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::volumioGetState Feb 26 22:27:46 loe qobuz-connect[6399]: 20260226 22:27:46.164 [6399.6399] INFO LocalConfigManager: [0x49bce8]: Starting Local Configuration server Feb 26 22:27:46 loe qobuz-connect[6399]: 20260226 22:27:46.164 [6399.6399] INFO SampleApp: Starting Local configuration server Feb 26 22:27:46 loe qobuz-connect[6399]: 20260226 22:27:46.165 [6399.6399] INFO SampleApp: Connected to UNIX socket client 0x486818 Feb 26 22:27:46 loe volumio[5800]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.79 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Feb 26 22:27:46 loe qobuz-connect[6399]: 20260226 22:27:46.253 [6399.6399] INFO SampleApp: Playback volume changed: 75 Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::volumioGetState Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::volumioGetState Feb 26 22:27:46 loe volumio[5800]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.mjORZRjMx8YIlyGajvB2CXSYA5r2.a53384b16fd4d7a180fdac1b5068092c.state.status' Feb 26 22:27:46 loe sudo[6412]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 26 22:27:46 loe sudo[6412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:46 loe sudo[6414]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 26 22:27:46 loe sudo[6412]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:46 loe sudo[6414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:46 loe sudo[6414]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:46 loe volumio[5800]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.79 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 26 22:27:46 loe volumio[5800]: info: TidalConnect service stoped! Feb 26 22:27:46 loe volumio[5800]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Feb 26 22:27:46 loe volumio[5800]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Feb 26 22:27:46 loe sudo[6426]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Feb 26 22:27:46 loe sudo[6426]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::volumioGetVisibleSources Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::volumioGetState Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 26 22:27:46 loe volumio[5800]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Feb 26 22:27:46 loe volumio[5800]: info: Received Get System Info Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 22:27:46 loe volumio[5800]: info: Discovery: Getting this device information Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::volumioGetState Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::volumioGetState Feb 26 22:27:46 loe volumio[5800]: info: Listing playlists Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Feb 26 22:27:46 loe volumio[5800]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Feb 26 22:27:46 loe systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Feb 26 22:27:47 loe sudo[6426]: pam_unix(sudo:session): session closed for user root Feb 26 22:27:47 loe volumio[5800]: info: Getting Spotify volume Feb 26 22:27:47 loe volumio[5800]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 22:27:47 loe volumio[5800]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 22:27:47 loe volumio[5800]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 26 22:27:47 loe volumio[5800]: errno: -111, Feb 26 22:27:47 loe volumio[5800]: code: 'ECONNREFUSED', Feb 26 22:27:47 loe volumio[5800]: syscall: 'connect', Feb 26 22:27:47 loe volumio[5800]: address: '127.0.0.1', Feb 26 22:27:47 loe volumio[5800]: port: 9879, Feb 26 22:27:47 loe volumio[5800]: response: undefined Feb 26 22:27:47 loe volumio[5800]: } Feb 26 22:27:47 loe volumio[5800]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 22:27:47 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 26 22:27:47 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:47 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:27:47 loe go-librespot[6443]: go-librespot daemon starting... Feb 26 22:27:47 loe go-librespot[6444]: time="2026-02-26T22:27:47+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:27:47 loe go-librespot[6444]: time="2026-02-26T22:27:47+01:00" level=debug msg="app state loaded" Feb 26 22:27:47 loe go-librespot[6444]: time="2026-02-26T22:27:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:27:48 loe go-librespot[6444]: time="2026-02-26T22:27:48+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:27:48 loe go-librespot[6444]: time="2026-02-26T22:27:48+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:27:48 loe go-librespot[6444]: time="2026-02-26T22:27:48+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:27:48 loe go-librespot[6444]: time="2026-02-26T22:27:48+01:00" level=info msg="zeroconf server listening on port 33991" Feb 26 22:27:48 loe go-librespot[6444]: time="2026-02-26T22:27:48+01:00" level=debug msg="obtained new client token: AAAfPeLWCQ8KYkQCH2Mlpvn22F3xzJfh2pnV32Harg8mSZhdZeK9yHlpCMR6fcipEafkxAunFIKcGDzK/FrhqXqMNmBGyvg9DK3KXrNgGg96PIdDolyj92OoECcen2TIh2vvaKiKot2YJgwgvPzF7ZiIhf5LsQ/1F6RNtAfxFFVc5sO+bAMh+AFtK5kAGziOFlfOQTLnxuf8ZsZzkJRRiQMztm8BPb0Uz0NO7DMZnHAlFaeRyWMigTIlCQ==" Feb 26 22:27:48 loe go-librespot[6444]: time="2026-02-26T22:27:48+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:27:48 loe go-librespot[6444]: time="2026-02-26T22:27:48+01:00" level=debug msg="completed keyexchange" Feb 26 22:27:48 loe go-librespot[6444]: time="2026-02-26T22:27:48+01:00" level=debug msg="completed challenge" Feb 26 22:27:48 loe go-librespot[6444]: time="2026-02-26T22:27:48+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:27:48 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:27:48 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:27:48 loe sudo[6454]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-26 22:26' Feb 26 22:27:48 loe sudo[6454]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"