-- Logs begin at Sat 2025-05-17 08:29:30 CEST, end at Sat 2025-05-17 08:59:14 CEST. -- May 17 08:58:02 stanzetta systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 08:58:02 stanzetta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1009. May 17 08:58:02 stanzetta systemd[1]: Stopped go-librespot Daemon. May 17 08:58:02 stanzetta systemd[1]: Started go-librespot Daemon. May 17 08:58:02 stanzetta go-librespot[20938]: go-librespot daemon starting... May 17 08:58:02 stanzetta go-librespot[20938]: time="2025-05-17T08:58:02+02:00" level=info msg="running go-librespot 0.2.0" May 17 08:58:02 stanzetta go-librespot[20938]: time="2025-05-17T08:58:02+02:00" level=debug msg="app state loaded" May 17 08:58:02 stanzetta go-librespot[20938]: time="2025-05-17T08:58:02+02:00" level=debug msg="stored credentials not found" May 17 08:58:02 stanzetta go-librespot[20938]: time="2025-05-17T08:58:02+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 17 08:58:03 stanzetta go-librespot[20938]: time="2025-05-17T08:58:03+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" May 17 08:58:03 stanzetta go-librespot[20938]: time="2025-05-17T08:58:03+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" May 17 08:58:03 stanzetta go-librespot[20938]: time="2025-05-17T08:58:03+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" May 17 08:58:03 stanzetta go-librespot[20938]: time="2025-05-17T08:58:03+02:00" level=info msg="zeroconf server listening on port 41115" May 17 08:58:03 stanzetta go-librespot[20938]: time="2025-05-17T08:58:03+02:00" level=debug msg="obtained new client token: AAB6AHJLmwjetltUz77oQ11Q5PAkyxdVNwaHPHkjY0m1AsHRWxANajvrs3CCQqlWCUyhlzgt2y/n0psJfs3e56ulRlFsDW4/hArYmV1OfAa+xE3kaz5I74IJBGoIJnmlV3wu2kmKe/XArcW+pBTKRjcAgMlFLxqmYGMDYq1TeyrMUcpO2jW93Y0OCWFJyhAeAPfIwRulgzi/MFrzaliISmtm8Y8QK1cfXFcKvc6GR+HNk4c9E0n9W9nLxdAX" May 17 08:58:03 stanzetta go-librespot[20938]: time="2025-05-17T08:58:03+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 17 08:58:03 stanzetta go-librespot[20938]: time="2025-05-17T08:58:03+02:00" level=debug msg="completed keyexchange" May 17 08:58:03 stanzetta go-librespot[20938]: time="2025-05-17T08:58:03+02:00" level=debug msg="completed challenge" May 17 08:58:03 stanzetta go-librespot[20938]: time="2025-05-17T08:58:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 17 08:58:03 stanzetta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 08:58:03 stanzetta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 08:58:04 stanzetta volumio[886]: info: Checking if install.sh is present May 17 08:58:04 stanzetta volumio[886]: info: Initializing connection to go-librespot Websocket May 17 08:58:04 stanzetta volumio[886]: info: Requirement already satisfied (use --upgrade to upgrade): camilladsp-plot==1.0.2 from git+https://github.com/HEnquist/pycamilladsp-plot.git@v1.0.2 in /usr/local/lib/python3.7/dist-packages May 17 08:58:04 stanzetta volumio[886]: info: Executing install.sh May 17 08:58:04 stanzetta volumio[886]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 08:58:04 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:04 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:04 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:04 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:04 stanzetta sudo[20962]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/audio_interface/fusiondsp/install.sh May 17 08:58:04 stanzetta sudo[20962]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:04 stanzetta volumio[886]: info: creating filters folder and copying demo filters May 17 08:58:04 stanzetta volumio[886]: info: creating filters folder and copying demo filters May 17 08:58:04 stanzetta volumio[886]: info: copying demo flters May 17 08:58:04 stanzetta volumio[886]: info: copying demo flters May 17 08:58:04 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:04 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:04 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:04 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:04 stanzetta volumio[886]: info: ./presets/ May 17 08:58:05 stanzetta volumio[886]: info: ./presets/2XEQ15/ May 17 08:58:05 stanzetta volumio[886]: info: ./presets/2XEQ15/.Bass-FusionDsp.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/ May 17 08:58:05 stanzetta volumio[886]: info: ./presets/2XEQ15/ May 17 08:58:05 stanzetta volumio[886]: info: ./presets/2XEQ15/.Bass-FusionDsp.json May 17 08:58:05 stanzetta sudo[20989]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/usr/bin/apt update May 17 08:58:05 stanzetta sudo[20989]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:05 stanzetta volumio[886]: info: ./presets/2XEQ15/.Soundtrack-FusionDsp.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/2XEQ15/.Classic-FusionDsp.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/2XEQ15/.Voice-FusionDsp.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/2XEQ15/.Rock-FusionDsp.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/PEQ/ May 17 08:58:05 stanzetta volumio[886]: info: ./presets/convfir/ May 17 08:58:05 stanzetta volumio[886]: info: ./presets/convfir/kef.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/convfir/test.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/EQ15/ May 17 08:58:05 stanzetta volumio[886]: info: ./presets/EQ15/.Bass-FusionDsp.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/EQ15/.Soundtrack-FusionDsp.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/EQ15/.Classic-FusionDsp.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/EQ15/.Voice-FusionDsp.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/EQ15/.Rock-FusionDsp.json May 17 08:58:05 stanzetta volumio[886]: info: Installing/fusiondsp dependencies May 17 08:58:05 stanzetta volumio[886]: info: ./presets/2XEQ15/.Soundtrack-FusionDsp.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/2XEQ15/.Classic-FusionDsp.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/2XEQ15/.Voice-FusionDsp.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/2XEQ15/.Rock-FusionDsp.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/PEQ/ May 17 08:58:05 stanzetta volumio[886]: info: ./presets/convfir/ May 17 08:58:05 stanzetta volumio[886]: info: ./presets/convfir/kef.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/convfir/test.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/EQ15/ May 17 08:58:05 stanzetta volumio[886]: info: ./presets/EQ15/.Bass-FusionDsp.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/EQ15/.Soundtrack-FusionDsp.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/EQ15/.Classic-FusionDsp.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/EQ15/.Voice-FusionDsp.json May 17 08:58:05 stanzetta volumio[886]: info: ./presets/EQ15/.Rock-FusionDsp.json May 17 08:58:05 stanzetta volumio[886]: info: Installing/fusiondsp dependencies May 17 08:58:05 stanzetta sudo[21001]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/bin/cp /data/plugins/audio_interface/fusiondsp/c/hw_params_arm /data/plugins/audio_interface/fusiondsp/hw_params May 17 08:58:05 stanzetta sudo[21001]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:05 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:05 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:05 stanzetta sudo[21001]: pam_unix(sudo:session): session closed for user root May 17 08:58:05 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:05 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:05 stanzetta sudo[21004]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/bin/chmod +x /data/plugins/audio_interface/fusiondsp/hw_params May 17 08:58:05 stanzetta sudo[21004]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:05 stanzetta sudo[21004]: pam_unix(sudo:session): session closed for user root May 17 08:58:05 stanzetta sudo[21006]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/usr/bin/apt-get -y install drc May 17 08:58:05 stanzetta sudo[21006]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:05 stanzetta volumio[886]: info: May 17 08:58:05 stanzetta volumio[886]: Reading package lists... May 17 08:58:05 stanzetta volumio[886]: info: May 17 08:58:05 stanzetta volumio[886]: Reading package lists... May 17 08:58:05 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:05 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:05 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:05 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:05 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:05 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:05 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:05 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:06 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:06 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:06 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:06 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:06 stanzetta volumio[886]: info: Building dependency tree... May 17 08:58:06 stanzetta volumio[886]: info: Building dependency tree... May 17 08:58:06 stanzetta volumio[886]: info: Reading state information... May 17 08:58:06 stanzetta volumio[886]: info: Reading state information... May 17 08:58:06 stanzetta systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 08:58:06 stanzetta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1010. May 17 08:58:06 stanzetta systemd[1]: Stopped go-librespot Daemon. May 17 08:58:06 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:06 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:06 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:06 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:06 stanzetta systemd[1]: Started go-librespot Daemon. May 17 08:58:06 stanzetta go-librespot[21151]: go-librespot daemon starting... May 17 08:58:06 stanzetta go-librespot[21151]: time="2025-05-17T08:58:06+02:00" level=info msg="running go-librespot 0.2.0" May 17 08:58:06 stanzetta go-librespot[21151]: time="2025-05-17T08:58:06+02:00" level=debug msg="app state loaded" May 17 08:58:06 stanzetta go-librespot[21151]: time="2025-05-17T08:58:06+02:00" level=debug msg="stored credentials not found" May 17 08:58:06 stanzetta go-librespot[21151]: time="2025-05-17T08:58:06+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 17 08:58:06 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:06 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:06 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:06 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:07 stanzetta go-librespot[21151]: time="2025-05-17T08:58:07+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 17 08:58:07 stanzetta go-librespot[21151]: time="2025-05-17T08:58:07+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 17 08:58:07 stanzetta go-librespot[21151]: time="2025-05-17T08:58:07+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 17 08:58:07 stanzetta go-librespot[21151]: time="2025-05-17T08:58:07+02:00" level=info msg="zeroconf server listening on port 37317" May 17 08:58:07 stanzetta go-librespot[21151]: time="2025-05-17T08:58:07+02:00" level=debug msg="obtained new client token: AAAlLKsVmw///4xubosVQpBWbq3EnlWODoVs2CvdQCR1I4wexEURCTrEPeNSPssUfG4cixDaIWOppfzn4Y6vCZgFp+OKzFuBA30AqzHHlQlqEAwFFigRf5uwmwX4F2zI04TEoavp4EekXGUjb8KWnzs4z+21aYd0/Ea3C18EL4kqV/bbv+aAeUQLyFNKqHxU+nRz4ADOr2e3eEUoKOGpnX9Ow5HU7Ez7qxmJJuMYBngmZjHY+fmpQMCpkg==" May 17 08:58:07 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:07 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:07 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:07 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:07 stanzetta go-librespot[21151]: time="2025-05-17T08:58:07+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 17 08:58:07 stanzetta go-librespot[21151]: time="2025-05-17T08:58:07+02:00" level=debug msg="completed keyexchange" May 17 08:58:07 stanzetta go-librespot[21151]: time="2025-05-17T08:58:07+02:00" level=debug msg="completed challenge" May 17 08:58:07 stanzetta go-librespot[21151]: time="2025-05-17T08:58:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 17 08:58:07 stanzetta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 08:58:07 stanzetta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 08:58:07 stanzetta volumio[886]: info: Initializing connection to go-librespot Websocket May 17 08:58:07 stanzetta volumio[886]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 08:58:07 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:07 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:07 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:07 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:07 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:07 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:07 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:07 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:08 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:08 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:08 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:08 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:08 stanzetta volumio[886]: info: drc is already the newest version (3.2.2~dfsg0-2). May 17 08:58:08 stanzetta sudo[21006]: pam_unix(sudo:session): session closed for user root May 17 08:58:08 stanzetta sudo[20380]: pam_unix(sudo:session): session closed for user root May 17 08:58:08 stanzetta volumio[886]: info: 0 upgraded, 0 newly installed, 0 to remove and 2 not upgraded. May 17 08:58:08 stanzetta volumio[886]: info: drc is already the newest version (3.2.2~dfsg0-2). May 17 08:58:08 stanzetta volumio[886]: info: 0 upgraded, 0 newly installed, 0 to remove and 2 not upgraded. May 17 08:58:08 stanzetta volumio[886]: info: Install script completed May 17 08:58:08 stanzetta volumio[886]: info: Adding reference to registry May 17 08:58:08 stanzetta volumio[886]: info: Done installing plugin. May 17 08:58:08 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 17 08:58:08 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 17 08:58:08 stanzetta volumio[886]: info: Folder /tmp/plugins removed May 17 08:58:08 stanzetta volumio[886]: info: Folder /tmp/downloaded_plugin.zip removed May 17 08:58:08 stanzetta volumio[886]: Plugin install end detected on script May 17 08:58:08 stanzetta volumio[886]: Plugin install end detected on script May 17 08:58:08 stanzetta volumio[886]: info: Folder /data/temp removed May 17 08:58:08 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:08 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:08 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:08 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:08 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:08 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:08 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:08 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:09 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:09 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:09 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:09 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:09 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:09 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:09 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:09 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:09 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:09 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:09 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:09 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:10 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:10 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:10 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:10 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:10 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:10 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:10 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:10 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:10 stanzetta volumio[886]: info: Initializing connection to go-librespot Websocket May 17 08:58:10 stanzetta volumio[886]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 08:58:10 stanzetta systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 08:58:10 stanzetta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1011. May 17 08:58:10 stanzetta systemd[1]: Stopped go-librespot Daemon. May 17 08:58:10 stanzetta systemd[1]: Started go-librespot Daemon. May 17 08:58:10 stanzetta go-librespot[21213]: go-librespot daemon starting... May 17 08:58:10 stanzetta go-librespot[21213]: time="2025-05-17T08:58:10+02:00" level=info msg="running go-librespot 0.2.0" May 17 08:58:10 stanzetta go-librespot[21213]: time="2025-05-17T08:58:10+02:00" level=debug msg="app state loaded" May 17 08:58:10 stanzetta go-librespot[21213]: time="2025-05-17T08:58:10+02:00" level=debug msg="stored credentials not found" May 17 08:58:10 stanzetta go-librespot[21213]: time="2025-05-17T08:58:10+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 17 08:58:10 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:10 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:10 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:10 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:11 stanzetta go-librespot[21213]: time="2025-05-17T08:58:11+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 17 08:58:11 stanzetta go-librespot[21213]: time="2025-05-17T08:58:11+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 17 08:58:11 stanzetta go-librespot[21213]: time="2025-05-17T08:58:11+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 17 08:58:11 stanzetta go-librespot[21213]: time="2025-05-17T08:58:11+02:00" level=info msg="zeroconf server listening on port 34161" May 17 08:58:11 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:11 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:11 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:11 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:11 stanzetta go-librespot[21213]: time="2025-05-17T08:58:11+02:00" level=debug msg="obtained new client token: AAAZ6/w2TOYUhGLrbPWzPRsVSpXQLomKZvmi521Ehoe57fBUTUrRtNzV3Ge50pPPl3FLbTT9/LdSIati1jLvYXcsMI2rnRE0pEWesnOU0Qex1ugneEVt8Ul8io59SBYrWqy95sqY3Tw4xJIs2uMJPL/f3BadcRmJ7+KevXkUJQ88OCm0vnyeBdTNelOhD4QJuXtqJxsDf1li1p6rQXOXLMfbdTzms8c/3n4m3INTNy3VD/UKf9ibIHp4MQ==" May 17 08:58:11 stanzetta go-librespot[21213]: time="2025-05-17T08:58:11+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 17 08:58:11 stanzetta go-librespot[21213]: time="2025-05-17T08:58:11+02:00" level=debug msg="completed keyexchange" May 17 08:58:11 stanzetta go-librespot[21213]: time="2025-05-17T08:58:11+02:00" level=debug msg="completed challenge" May 17 08:58:11 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:11 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:11 stanzetta go-librespot[21213]: time="2025-05-17T08:58:11+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 17 08:58:11 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:11 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:11 stanzetta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 08:58:11 stanzetta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 08:58:11 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:11 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:11 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:11 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:12 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:12 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:12 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:12 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:12 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:12 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:12 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:12 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:12 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:12 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:12 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:12 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:12 stanzetta sudo[20989]: pam_unix(sudo:session): session closed for user root May 17 08:58:12 stanzetta sudo[21222]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/usr/bin/apt -y install python3-aiohttp python3-pip May 17 08:58:12 stanzetta sudo[21222]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:13 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:13 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:13 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:13 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:13 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:13 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:13 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:13 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:13 stanzetta volumio[886]: info: Initializing connection to go-librespot Websocket May 17 08:58:13 stanzetta volumio[886]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 08:58:13 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:13 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:13 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:13 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:13 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:13 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:13 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:13 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:14 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:14 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:14 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:14 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:14 stanzetta systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 08:58:14 stanzetta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1012. May 17 08:58:14 stanzetta systemd[1]: Stopped go-librespot Daemon. May 17 08:58:14 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:14 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:14 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:14 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:14 stanzetta systemd[1]: Started go-librespot Daemon. May 17 08:58:14 stanzetta go-librespot[21240]: go-librespot daemon starting... May 17 08:58:14 stanzetta go-librespot[21240]: time="2025-05-17T08:58:14+02:00" level=info msg="running go-librespot 0.2.0" May 17 08:58:14 stanzetta go-librespot[21240]: time="2025-05-17T08:58:14+02:00" level=debug msg="app state loaded" May 17 08:58:14 stanzetta go-librespot[21240]: time="2025-05-17T08:58:14+02:00" level=debug msg="stored credentials not found" May 17 08:58:14 stanzetta go-librespot[21240]: time="2025-05-17T08:58:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 17 08:58:14 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:14 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:14 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:14 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:15 stanzetta go-librespot[21240]: time="2025-05-17T08:58:15+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" May 17 08:58:15 stanzetta go-librespot[21240]: time="2025-05-17T08:58:15+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" May 17 08:58:15 stanzetta go-librespot[21240]: time="2025-05-17T08:58:15+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" May 17 08:58:15 stanzetta go-librespot[21240]: time="2025-05-17T08:58:15+02:00" level=info msg="zeroconf server listening on port 39507" May 17 08:58:15 stanzetta go-librespot[21240]: time="2025-05-17T08:58:15+02:00" level=debug msg="obtained new client token: AAAaxdTfUFQjfn16JnS1m/5y0YQYa17fAuWbOi11qVDyRhMiqq2zMOOgsgiylFH4poR9QekMedA0UimIvxIClDvtkRGxKCu6VCp+4KuhJyqqo2phB8AnaEtJ+FSyb0aQsg8576K8It+JipKCrswOU6mwj0xrLGbiKJlr/fVHZzekGqTQ6IaufULsmboP7mzpTAEB9muXDESRWmfDDCUMb3G3Z55aIkDq/NG69sBau2F8EnL9OIGH5DYkxA==" May 17 08:58:15 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:15 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:15 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:15 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:15 stanzetta go-librespot[21240]: time="2025-05-17T08:58:15+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 17 08:58:15 stanzetta go-librespot[21240]: time="2025-05-17T08:58:15+02:00" level=debug msg="completed keyexchange" May 17 08:58:15 stanzetta go-librespot[21240]: time="2025-05-17T08:58:15+02:00" level=debug msg="completed challenge" May 17 08:58:15 stanzetta go-librespot[21240]: time="2025-05-17T08:58:15+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 17 08:58:15 stanzetta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 08:58:15 stanzetta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 08:58:15 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:15 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:15 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:15 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:15 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:15 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:15 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:15 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:16 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:16 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:16 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:16 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:16 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:16 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:16 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:16 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:16 stanzetta volumio[886]: info: Initializing connection to go-librespot Websocket May 17 08:58:16 stanzetta volumio[886]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 08:58:16 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:16 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:16 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:16 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:17 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:17 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:17 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:17 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:17 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:17 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:17 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:17 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:17 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:17 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:17 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:17 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:17 stanzetta sudo[21222]: pam_unix(sudo:session): session closed for user root May 17 08:58:17 stanzetta sudo[21249]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/tar -xvf fusiondsp.service.tar -C / May 17 08:58:17 stanzetta sudo[21249]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:18 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:18 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:18 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:18 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:18 stanzetta sudo[21249]: pam_unix(sudo:session): session closed for user root May 17 08:58:18 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:18 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:18 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:18 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:18 stanzetta systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 08:58:18 stanzetta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1013. May 17 08:58:18 stanzetta systemd[1]: Stopped go-librespot Daemon. May 17 08:58:18 stanzetta systemd[1]: Started go-librespot Daemon. May 17 08:58:18 stanzetta go-librespot[21252]: go-librespot daemon starting... May 17 08:58:18 stanzetta go-librespot[21252]: time="2025-05-17T08:58:18+02:00" level=info msg="running go-librespot 0.2.0" May 17 08:58:18 stanzetta go-librespot[21252]: time="2025-05-17T08:58:18+02:00" level=debug msg="app state loaded" May 17 08:58:18 stanzetta go-librespot[21252]: time="2025-05-17T08:58:18+02:00" level=debug msg="stored credentials not found" May 17 08:58:18 stanzetta go-librespot[21252]: time="2025-05-17T08:58:18+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 17 08:58:18 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:18 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:18 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:18 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:18 stanzetta volumio[886]: info: Enabling plugin fusiondsp May 17 08:58:18 stanzetta volumio[886]: info: Loading plugin "fusiondsp"... May 17 08:58:18 stanzetta go-librespot[21252]: time="2025-05-17T08:58:18+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" May 17 08:58:18 stanzetta go-librespot[21252]: time="2025-05-17T08:58:18+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" May 17 08:58:18 stanzetta go-librespot[21252]: time="2025-05-17T08:58:18+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" May 17 08:58:18 stanzetta go-librespot[21252]: time="2025-05-17T08:58:18+02:00" level=info msg="zeroconf server listening on port 37269" May 17 08:58:19 stanzetta go-librespot[21252]: time="2025-05-17T08:58:19+02:00" level=debug msg="obtained new client token: AAAw/g76gwB3O5a6l+Re6ROuqEr4BWBB40ZB2SEPqliB1WRa8PgZ6PIQXjIR8Gl4eQXbsR/H3Mbzo3GThDKl+S6qHN0qXImdiMJ2XW81fF1N28svS/6nbGS566JYHF3v+R/ic1wVfdRDzahNQq95Fmp8/1wHmFddVPgHqf3uIWh+5wUJlxH/WSysnA5Ihl7fL2QupZqJwiv8LO5Vtr5rWQWVADXHjnlU6mYD95aqcVtW0N8I6ym2uvjSmQ==" May 17 08:58:19 stanzetta go-librespot[21252]: time="2025-05-17T08:58:19+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 17 08:58:19 stanzetta go-librespot[21252]: time="2025-05-17T08:58:19+02:00" level=debug msg="completed keyexchange" May 17 08:58:19 stanzetta go-librespot[21252]: time="2025-05-17T08:58:19+02:00" level=debug msg="completed challenge" May 17 08:58:19 stanzetta go-librespot[21252]: time="2025-05-17T08:58:19+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 17 08:58:19 stanzetta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 08:58:19 stanzetta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 08:58:20 stanzetta volumio[886]: info: Preparing to generate the ALSA configuration file May 17 08:58:20 stanzetta volumio[886]: info: Initializing connection to go-librespot Websocket May 17 08:58:20 stanzetta volumio[886]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 17 08:58:20 stanzetta volumio[886]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf May 17 08:58:20 stanzetta volumio[886]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 08:58:20 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:20 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:20 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:20 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:20 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:20 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:20 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:20 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:20 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:20 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:20 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:20 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:21 stanzetta sudo[21261]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/chown -R volumio cgui May 17 08:58:21 stanzetta sudo[21261]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:21 stanzetta sudo[21261]: pam_unix(sudo:session): session closed for user root May 17 08:58:21 stanzetta sudo[21263]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/chgrp -R volumio cgui May 17 08:58:21 stanzetta sudo[21263]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:21 stanzetta sudo[21263]: pam_unix(sudo:session): session closed for user root May 17 08:58:21 stanzetta sudo[21265]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/rm cgui-1.0.0.zip May 17 08:58:21 stanzetta sudo[21265]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:21 stanzetta sudo[21265]: pam_unix(sudo:session): session closed for user root May 17 08:58:21 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:21 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:21 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:21 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:21 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:21 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:21 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:21 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:21 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:21 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:21 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:21 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:22 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:22 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:22 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:22 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:22 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:22 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:22 stanzetta volumio[886]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 17 08:58:22 stanzetta volumio[886]: info: Reading ALSA contributions from plugins. May 17 08:58:22 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:22 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:22 stanzetta volumio[886]: info: Asound.conf file written May 17 08:58:22 stanzetta systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 08:58:22 stanzetta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1014. May 17 08:58:22 stanzetta systemd[1]: Stopped go-librespot Daemon. May 17 08:58:22 stanzetta sudo[21270]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 17 08:58:22 stanzetta sudo[21270]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:22 stanzetta systemd[1]: Started go-librespot Daemon. May 17 08:58:22 stanzetta sudo[21270]: pam_unix(sudo:session): session closed for user root May 17 08:58:22 stanzetta go-librespot[21269]: go-librespot daemon starting... May 17 08:58:22 stanzetta go-librespot[21269]: time="2025-05-17T08:58:22+02:00" level=info msg="running go-librespot 0.2.0" May 17 08:58:22 stanzetta go-librespot[21269]: time="2025-05-17T08:58:22+02:00" level=debug msg="app state loaded" May 17 08:58:22 stanzetta go-librespot[21269]: time="2025-05-17T08:58:22+02:00" level=debug msg="stored credentials not found" May 17 08:58:22 stanzetta go-librespot[21269]: time="2025-05-17T08:58:22+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 17 08:58:22 stanzetta go-librespot[21269]: time="2025-05-17T08:58:22+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" May 17 08:58:22 stanzetta go-librespot[21269]: time="2025-05-17T08:58:22+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" May 17 08:58:22 stanzetta go-librespot[21269]: time="2025-05-17T08:58:22+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" May 17 08:58:23 stanzetta go-librespot[21269]: time="2025-05-17T08:58:23+02:00" level=info msg="zeroconf server listening on port 36865" May 17 08:58:23 stanzetta go-librespot[21269]: time="2025-05-17T08:58:23+02:00" level=debug msg="obtained new client token: AACaDXVrmSGqTM8DYqJ1WewpCsgYCzcRlEJ/guTaghLQTcA1yt3z5nKOSYAp/aVLutq+u6Pf3Jbtw403X/b/EZkEmdP9YXU+n5DjLSwvRGdZflusd+Qw4aXcJedD6ALFxShmJoiiwPFHe33WoGmWWgWo0bMJ434cwQ4Yh3X/eiNCGHdkNcJO3400YgJVSrtD+9oK1zqGJ2T9VeIpLP4pZ5OCljWSD1oL5RPGWNVXx4htHn+xtg69TueSKQ==" May 17 08:58:23 stanzetta go-librespot[21269]: time="2025-05-17T08:58:23+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 17 08:58:23 stanzetta go-librespot[21269]: time="2025-05-17T08:58:23+02:00" level=debug msg="completed keyexchange" May 17 08:58:23 stanzetta go-librespot[21269]: time="2025-05-17T08:58:23+02:00" level=debug msg="completed challenge" May 17 08:58:23 stanzetta go-librespot[21269]: time="2025-05-17T08:58:23+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 17 08:58:23 stanzetta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 08:58:23 stanzetta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 08:58:26 stanzetta systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 08:58:26 stanzetta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1015. May 17 08:58:26 stanzetta systemd[1]: Stopped go-librespot Daemon. May 17 08:58:26 stanzetta go-librespot[21297]: go-librespot daemon starting... May 17 08:58:26 stanzetta systemd[1]: Started go-librespot Daemon. May 17 08:58:26 stanzetta go-librespot[21297]: time="2025-05-17T08:58:26+02:00" level=info msg="running go-librespot 0.2.0" May 17 08:58:26 stanzetta go-librespot[21297]: time="2025-05-17T08:58:26+02:00" level=debug msg="app state loaded" May 17 08:58:26 stanzetta go-librespot[21297]: time="2025-05-17T08:58:26+02:00" level=debug msg="stored credentials not found" May 17 08:58:26 stanzetta go-librespot[21297]: time="2025-05-17T08:58:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 17 08:58:26 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:58:26 stanzetta volumio[886]: info: Output device has changed, restarting MPD May 17 08:58:26 stanzetta sudo[21305]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 17 08:58:26 stanzetta sudo[21305]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:26 stanzetta sudo[21305]: pam_unix(sudo:session): session closed for user root May 17 08:58:26 stanzetta volumio[886]: info: Output device has changed, restarting Shairport Sync May 17 08:58:26 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:26 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 17 08:58:26 stanzetta sudo[21308]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 17 08:58:26 stanzetta sudo[21308]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:26 stanzetta systemd[1]: Stopping MPD OLED Plugin... May 17 08:58:26 stanzetta systemd[1]: mpd_oled_plugin.service: Main process exited, code=killed, status=15/TERM May 17 08:58:26 stanzetta systemd[1]: mpd_oled_plugin.service: Succeeded. May 17 08:58:26 stanzetta systemd[1]: Stopped MPD OLED Plugin. May 17 08:58:26 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:58:26 stanzetta volumio[886]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 17 08:58:26 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:58:26 stanzetta volumio[886]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 17 08:58:26 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:26 stanzetta volumio[886]: info: QobuzConnect: setDeactiveState invoked May 17 08:58:26 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:26 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:26 stanzetta vtcs[19417]: [2025-05-17 08:58:26.975] [tisoc] [error] [SpkconServer.cpp:376] recv error. socket disconnected May 17 08:58:26 stanzetta vtcs[19417]: [2025-05-17 08:58:26.975] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE May 17 08:58:27 stanzetta volumio[886]: info: PLUGIN START: fusiondsp May 17 08:58:27 stanzetta volumio[886]: info: Loading i18n strings for locale it May 17 08:58:27 stanzetta go-librespot[21297]: time="2025-05-17T08:58:27+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" May 17 08:58:27 stanzetta go-librespot[21297]: time="2025-05-17T08:58:27+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" May 17 08:58:27 stanzetta go-librespot[21297]: time="2025-05-17T08:58:27+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" May 17 08:58:27 stanzetta sudo[21320]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 17 08:58:27 stanzetta sudo[21320]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:27 stanzetta go-librespot[21297]: time="2025-05-17T08:58:27+02:00" level=info msg="zeroconf server listening on port 34915" May 17 08:58:27 stanzetta go-librespot[21297]: time="2025-05-17T08:58:27+02:00" level=debug msg="obtained new client token: AABWEy6GHAXxI8d4XN8DqXFB52C3tqjSj1GGqaNZKyNTENDE8oh2SeJXoL75MAW0BT26ZmvpiGSReLHPaw68T5Z1QYmNNGJHXQLUVcby+I2iUnZJ6A7Ajrb8CevL+8YutTTz3xrvLw/RAld0y1cZrcAQq7LPZtr+94Ue0hAqeTAA8t4ELrvlpP0cAFdZt6a3Rfsajf5gXiqp5QbCuPwm4YomlbnWxurU6hgZ2B/eg5dS0kNb9OYBzmXLlw==" May 17 08:58:27 stanzetta go-librespot[21297]: time="2025-05-17T08:58:27+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 17 08:58:27 stanzetta go-librespot[21297]: time="2025-05-17T08:58:27+02:00" level=debug msg="completed keyexchange" May 17 08:58:27 stanzetta go-librespot[21297]: time="2025-05-17T08:58:27+02:00" level=debug msg="completed challenge" May 17 08:58:27 stanzetta go-librespot[21297]: time="2025-05-17T08:58:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 17 08:58:31 stanzetta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 08:58:31 stanzetta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 08:58:31 stanzetta systemd[1]: Stopping Music Player Daemon... May 17 08:58:31 stanzetta systemd[1]: Stopping Volumio Tidal Connect Service... May 17 08:58:31 stanzetta systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM May 17 08:58:31 stanzetta systemd[1]: vtcs.service: Succeeded. May 17 08:58:31 stanzetta systemd[1]: Stopped Volumio Tidal Connect Service. May 17 08:58:31 stanzetta sudo[21320]: pam_unix(sudo:session): session closed for user root May 17 08:58:33 stanzetta volumio-remote-updater[565]: [2025-05-17 08:58:33] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] May 17 08:58:34 stanzetta systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 08:58:34 stanzetta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1016. May 17 08:58:34 stanzetta systemd[1]: Stopped go-librespot Daemon. May 17 08:58:34 stanzetta systemd[1]: Started go-librespot Daemon. May 17 08:58:34 stanzetta go-librespot[21383]: go-librespot daemon starting... May 17 08:58:34 stanzetta go-librespot[21383]: time="2025-05-17T08:58:34+02:00" level=info msg="running go-librespot 0.2.0" May 17 08:58:34 stanzetta go-librespot[21383]: time="2025-05-17T08:58:34+02:00" level=debug msg="app state loaded" May 17 08:58:34 stanzetta go-librespot[21383]: time="2025-05-17T08:58:34+02:00" level=debug msg="stored credentials not found" May 17 08:58:34 stanzetta go-librespot[21383]: time="2025-05-17T08:58:34+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 17 08:58:38 stanzetta volumio-remote-updater[565]: [2025-05-17 08:58:38] [connect] Successful connection May 17 08:58:39 stanzetta go-librespot[21383]: time="2025-05-17T08:58:39+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 17 08:58:39 stanzetta go-librespot[21383]: time="2025-05-17T08:58:39+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 17 08:58:39 stanzetta go-librespot[21383]: time="2025-05-17T08:58:39+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 17 08:58:39 stanzetta go-librespot[21383]: time="2025-05-17T08:58:39+02:00" level=info msg="zeroconf server listening on port 40855" May 17 08:58:39 stanzetta go-librespot[21383]: time="2025-05-17T08:58:39+02:00" level=debug msg="obtained new client token: AACUFq7FAdc/U1hmksgF3TGKboKkWTH4CgeE2ZK1+TKNYDqoC30TQ72OgO3Y0r6rjz3b/imRKcjxs1URBd0mesBXjVFG4fDb83S4oeQpAHmS+nRS6h09RcVDAmPAEKDaS0m4z1OpmlDoa2EMrVE/FYV8tS4Kkg65jnpYbsNATJ7SMQ/cmP0Fb30+1vKRvKgflle+YFVDlmLxNGsqr8jPRvwUs4vhBt3tiAq1UywwZsbVA2qEpEo0g9i0ht31" May 17 08:58:39 stanzetta go-librespot[21383]: time="2025-05-17T08:58:39+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 17 08:58:39 stanzetta go-librespot[21383]: time="2025-05-17T08:58:39+02:00" level=debug msg="completed keyexchange" May 17 08:58:39 stanzetta go-librespot[21383]: time="2025-05-17T08:58:39+02:00" level=debug msg="completed challenge" May 17 08:58:39 stanzetta go-librespot[21383]: time="2025-05-17T08:58:39+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 17 08:58:39 stanzetta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 08:58:39 stanzetta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 08:58:42 stanzetta systemd[1]: mpd.service: Succeeded. May 17 08:58:42 stanzetta systemd[1]: Stopped Music Player Daemon. May 17 08:58:42 stanzetta systemd[1]: Starting Music Player Daemon... May 17 08:58:42 stanzetta sudo[21405]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 17 08:58:42 stanzetta sudo[21405]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:42 stanzetta sudo[21405]: pam_unix(sudo:session): session closed for user root May 17 08:58:42 stanzetta systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 08:58:42 stanzetta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1017. May 17 08:58:42 stanzetta systemd[1]: Stopped go-librespot Daemon. May 17 08:58:42 stanzetta systemd[1]: Started go-librespot Daemon. May 17 08:58:42 stanzetta go-librespot[21408]: go-librespot daemon starting... May 17 08:58:42 stanzetta go-librespot[21408]: time="2025-05-17T08:58:42+02:00" level=info msg="running go-librespot 0.2.0" May 17 08:58:42 stanzetta go-librespot[21408]: time="2025-05-17T08:58:42+02:00" level=debug msg="app state loaded" May 17 08:58:42 stanzetta go-librespot[21408]: time="2025-05-17T08:58:42+02:00" level=debug msg="stored credentials not found" May 17 08:58:42 stanzetta go-librespot[21408]: time="2025-05-17T08:58:42+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 17 08:58:43 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 17 08:58:43 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:43 stanzetta volumio[886]: info: FusionDsp - mixtype--------------------- Hardware May 17 08:58:43 stanzetta volumio[886]: info: Preparing to generate the ALSA configuration file May 17 08:58:43 stanzetta volumio[886]: info: Done. May 17 08:58:43 stanzetta volumio[886]: info: Initializing connection to go-librespot Websocket May 17 08:58:43 stanzetta volumio[886]: info: Discovery: Disconnected from remote: 192.168.1.5 May 17 08:58:43 stanzetta volumio[886]: info: MRS: Cleaning up device: 1da44f0c-764f-465c-8a3f-e3b7d6ef0a6b May 17 08:58:43 stanzetta volumio[886]: info: Removing audio output: May 17 08:58:43 stanzetta volumio[886]: info: Discovery: Disconnected from remote: 192.168.1.5 May 17 08:58:43 stanzetta volumio[886]: info: Discovery: Disconnected from remote: 192.168.1.5 May 17 08:58:43 stanzetta volumio[886]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 17 08:58:43 stanzetta volumio[886]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 17 08:58:43 stanzetta volumio[886]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf May 17 08:58:43 stanzetta volumio[886]: info: Reading ALSA contributions from plugins. May 17 08:58:43 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:43 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:43 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:43 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:43 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:43 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:43 stanzetta volumio[886]: info: Enabling plugin fusiondsp May 17 08:58:43 stanzetta volumio[886]: info: Loading plugin "fusiondsp"... May 17 08:58:46 stanzetta sudo[21435]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 17 08:58:46 stanzetta sudo[21430]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 17 08:58:46 stanzetta sudo[21435]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:46 stanzetta sudo[21430]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:46 stanzetta sudo[21435]: pam_unix(sudo:session): session closed for user root May 17 08:58:46 stanzetta sudo[21430]: pam_unix(sudo:session): session closed for user root May 17 08:58:46 stanzetta sudo[21438]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 17 08:58:46 stanzetta sudo[21438]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:46 stanzetta systemd[1]: Stopping Volumio Qobuz Connect Service... May 17 08:58:46 stanzetta qobuz-connect[19367]: 20250517 08:58:46.723 [19367.19367] INFO SampleApp: Stopping Local configuration server May 17 08:58:46 stanzetta qobuz-connect[19367]: 20250517 08:58:46.733 [19367.19367] INFO SampleApp: shat down connection on UNIX socket May 17 08:58:46 stanzetta systemd[1]: qobuz-connect.service: Succeeded. May 17 08:58:46 stanzetta systemd[1]: Stopped Volumio Qobuz Connect Service. May 17 08:58:46 stanzetta go-librespot[21408]: time="2025-05-17T08:58:46+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 17 08:58:46 stanzetta go-librespot[21408]: time="2025-05-17T08:58:46+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 17 08:58:46 stanzetta go-librespot[21408]: time="2025-05-17T08:58:46+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 17 08:58:46 stanzetta go-librespot[21408]: time="2025-05-17T08:58:46+02:00" level=info msg="zeroconf server listening on port 42073" May 17 08:58:46 stanzetta systemd[1]: Started Volumio Qobuz Connect Service. May 17 08:58:46 stanzetta sudo[21438]: pam_unix(sudo:session): session closed for user root May 17 08:58:46 stanzetta go-librespot[21408]: time="2025-05-17T08:58:46+02:00" level=debug msg="obtained new client token: AACrTLLgzApLZV0vuGheEui9GTIoKbGOmxCLQ/IznCamXipRqJ+gID76R741dv6DeD0aY1LIP3TlaiXkSB/NnOKcIFKAjzCzNgY1QNJdqCoL4MZ3dHObt/ahfoK76qElc8VYPu9vAuiSCI092leH5Ce7btZX59zqiSjDjW4D5FRi8+XTZoa7jb5uV0o+eIb/jGbWA6kK9M4Rc2BvlUEhbbTM6ZEBw9tbl5ZywRPVJWxeSJyeOGxKP7uQry1R" May 17 08:58:47 stanzetta go-librespot[21408]: time="2025-05-17T08:58:47+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 17 08:58:47 stanzetta go-librespot[21408]: time="2025-05-17T08:58:47+02:00" level=debug msg="completed keyexchange" May 17 08:58:47 stanzetta go-librespot[21408]: time="2025-05-17T08:58:47+02:00" level=debug msg="completed challenge" May 17 08:58:47 stanzetta go-librespot[21408]: time="2025-05-17T08:58:47+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 17 08:58:47 stanzetta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 08:58:47 stanzetta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 08:58:49 stanzetta volumio[886]: info: Applying required configuration parameters for plugin fusiondsp May 17 08:58:49 stanzetta volumio[886]: info: TidalConnect service stoped! May 17 08:58:49 stanzetta volumio[886]: info: MPD Permissions set May 17 08:58:49 stanzetta volumio[886]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists May 17 08:58:49 stanzetta volumio[886]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo May 17 08:58:49 stanzetta volumio[886]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists May 17 08:58:49 stanzetta volumio[886]: info: camilladsp service started and running in background, instance 3 May 17 08:58:49 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:49 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:58:49 stanzetta volumio[886]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 384000 <-AAAAAAAAAAAAA May 17 08:58:49 stanzetta volumio[886]: info: FusionDsp loaded May 17 08:58:49 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 17 08:58:49 stanzetta volumio[886]: info: FusionDsp - Reporting Fusion DSP Enabled May 17 08:58:49 stanzetta volumio[886]: info: Adding Signal Path Element [object Object] May 17 08:58:49 stanzetta volumio[886]: info: Adding fusiondspeq DSP Signal Path Element May 17 08:58:49 stanzetta volumio[886]: info: FusionDsp - ---- installed callbackRead May 17 08:58:49 stanzetta volumio[886]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 17 08:58:49 stanzetta sudo[21461]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service May 17 08:58:49 stanzetta sudo[21461]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:49 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:49 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:49 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 17 08:58:49 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate from file: 44100 May 17 08:58:49 stanzetta volumio[886]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 17 08:58:49 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 17 08:58:49 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate from file: 44100 May 17 08:58:49 stanzetta volumio[886]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 17 08:58:49 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 17 08:58:49 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate from file: 44100 May 17 08:58:49 stanzetta volumio[886]: info: camilladsp stopping service pid 21453... May 17 08:58:49 stanzetta systemd[1]: Started FusionDsp Daemon. May 17 08:58:49 stanzetta sudo[21461]: pam_unix(sudo:session): session closed for user root May 17 08:58:49 stanzetta volumio[886]: info: camilladsp service terminated, instance 3 May 17 08:58:49 stanzetta volumio[886]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 17 08:58:49 stanzetta volumio[886]: info: camilladsp service started and running in background, instance 3 May 17 08:58:49 stanzetta volumio[886]: verbose: New Socket.io Connection to 192.168.1.4:3000 from 192.168.1.5 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 May 17 08:58:49 stanzetta volumio[886]: verbose: New Socket.io Connection to 192.168.1.4 from 192.168.1.3 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:138.0) Gecko/20100101 Firefox/138.0 Engine version: 3 Transport: polling Total Clients: 3 May 17 08:58:49 stanzetta volumio[886]: verbose: New Socket.io Connection to 192.168.1.4 from 192.168.1.3 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:138.0) Gecko/20100101 Firefox/138.0 Engine version: 3 Transport: polling Total Clients: 4 May 17 08:58:49 stanzetta volumio[886]: info: TidalConnect service stoped! May 17 08:58:50 stanzetta volumio[886]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 17 08:58:50 stanzetta volumio[886]: info: QobuzConnect: setDeactiveState invoked May 17 08:58:50 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:50 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:50 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:50 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:50 stanzetta volumio[886]: info: Error connecting to go-librespot Websocket: Error: socket hang up May 17 08:58:50 stanzetta volumio[886]: info: MRS: Pushing audio output on request May 17 08:58:50 stanzetta volumio[886]: info: MRS: Pushing multiroomSync output May 17 08:58:50 stanzetta volumio[886]: info: Discovery: Connected to remote: 192.168.1.5 May 17 08:58:50 stanzetta volumio[886]: error: FusionDsp - WebSocket error: [object Object] May 17 08:58:50 stanzetta volumio[886]: verbose: New Socket.io Connection to 192.168.1.4:3000 from 192.168.1.5 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 May 17 08:58:50 stanzetta volumio[886]: info: Executing endpoint qc_getconfig May 17 08:58:50 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 17 08:58:50 stanzetta qobuz-connect[21442]: 20250517 08:58:50.121 [21442.21442] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 17 08:58:50 stanzetta volumio[886]: verbose: New Socket.io Connection to 192.168.1.4 from 192.168.1.3 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:138.0) Gecko/20100101 Firefox/138.0 Engine version: 3 Transport: polling Total Clients: 6 May 17 08:58:50 stanzetta qobuz-connect[21442]: 20250517 08:58:50.132 [21442.21442] INFO VolumeManager: [0x1cfda10]: Setting new playback volume: 75 May 17 08:58:50 stanzetta qobuz-connect[21442]: 20250517 08:58:50.138 [21442.21442] INFO VolumeManager: [0x1cfda10]: Setting new mute state: 0 May 17 08:58:50 stanzetta qobuz-connect[21442]: 20250517 08:58:50.138 [21442.21442] INFO QobuzConnect: [0x1cfe3e0]: Client initialized! May 17 08:58:50 stanzetta qobuz-connect[21442]: 20250517 08:58:50.138 [21442.21442] INFO SampleApp: Starting Avahi advertising, name: Stanzetta, service name: _qobuz-connect._tcp May 17 08:58:50 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:50 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:50 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:50 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:50 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:50 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:50 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:50 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:50 stanzetta qobuz-connect[21442]: 20250517 08:58:50.170 [21442.21442] INFO LocalConfigManager: [0x1cfd2f0]: Starting Local Configuration server May 17 08:58:50 stanzetta qobuz-connect[21442]: 20250517 08:58:50.170 [21442.21442] INFO SampleApp: Starting Local configuration server May 17 08:58:50 stanzetta qobuz-connect[21442]: 20250517 08:58:50.170 [21442.21442] INFO SampleApp: Connected to UNIX socket client 0x1cf2f60 May 17 08:58:50 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 17 08:58:50 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:50 stanzetta volumio[886]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 May 17 08:58:50 stanzetta volumio[886]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 May 17 08:58:50 stanzetta volumio[886]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 17 08:58:50 stanzetta volumio[886]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 May 17 08:58:50 stanzetta volumio[886]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 May 17 08:58:50 stanzetta qobuz-connect[21442]: 20250517 08:58:50.271 [21442.21442] INFO SampleApp: Playback volume changed: 75 May 17 08:58:50 stanzetta volumio[886]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 May 17 08:58:50 stanzetta volumio[886]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 17 08:58:50 stanzetta volumio[886]: info: QobuzConnect: QOBUZ Connect daemon connected May 17 08:58:50 stanzetta volumio[886]: error: FusionDsp - WebSocket error: [object Object] May 17 08:58:50 stanzetta volumio[886]: error: FusionDsp - WebSocket error: [object Object] May 17 08:58:50 stanzetta systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 08:58:50 stanzetta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1018. May 17 08:58:50 stanzetta systemd[1]: Stopped go-librespot Daemon. May 17 08:58:50 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:50 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:50 stanzetta systemd[1]: Started go-librespot Daemon. May 17 08:58:50 stanzetta go-librespot[21479]: go-librespot daemon starting... May 17 08:58:50 stanzetta go-librespot[21479]: time="2025-05-17T08:58:50+02:00" level=info msg="running go-librespot 0.2.0" May 17 08:58:50 stanzetta go-librespot[21479]: time="2025-05-17T08:58:50+02:00" level=debug msg="app state loaded" May 17 08:58:50 stanzetta go-librespot[21479]: time="2025-05-17T08:58:50+02:00" level=debug msg="stored credentials not found" May 17 08:58:50 stanzetta go-librespot[21479]: time="2025-05-17T08:58:50+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 17 08:58:50 stanzetta volumio[886]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 17 08:58:50 stanzetta volumio[886]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 17 08:58:50 stanzetta volumio[886]: info: Starting Shairport Sync May 17 08:58:50 stanzetta sudo[21488]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 17 08:58:50 stanzetta sudo[21488]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:50 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:50 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:50 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:50 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:50 stanzetta systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 17 08:58:50 stanzetta systemd[1]: shairport-sync.service: Succeeded. May 17 08:58:50 stanzetta systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 17 08:58:50 stanzetta volumio[886]: info: Asound.conf file unchanged, so no further update is needed May 17 08:58:50 stanzetta volumio[886]: info: Output device has changed, restarting MPD May 17 08:58:50 stanzetta systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 17 08:58:50 stanzetta sudo[21488]: pam_unix(sudo:session): session closed for user root May 17 08:58:50 stanzetta sudo[21492]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 17 08:58:50 stanzetta sudo[21492]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:50 stanzetta volumio[886]: info: Output device has changed, restarting Shairport Sync May 17 08:58:50 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:50 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 17 08:58:50 stanzetta sudo[21492]: pam_unix(sudo:session): session closed for user root May 17 08:58:50 stanzetta sudo[21497]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 17 08:58:50 stanzetta sudo[21497]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:50 stanzetta go-librespot[21479]: time="2025-05-17T08:58:50+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 17 08:58:50 stanzetta go-librespot[21479]: time="2025-05-17T08:58:50+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 17 08:58:50 stanzetta go-librespot[21479]: time="2025-05-17T08:58:50+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 17 08:58:51 stanzetta go-librespot[21479]: time="2025-05-17T08:58:51+02:00" level=info msg="zeroconf server listening on port 41543" May 17 08:58:51 stanzetta systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 17 08:58:51 stanzetta systemd[1]: mpd.service: Succeeded. May 17 08:58:51 stanzetta systemd[1]: Stopped Music Player Daemon. May 17 08:58:51 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:58:51 stanzetta volumio[886]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 17 08:58:51 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:58:51 stanzetta volumio[886]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 17 08:58:51 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:51 stanzetta volumio[886]: info: QobuzConnect: setDeactiveState invoked May 17 08:58:51 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:51 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:51 stanzetta systemd[1]: Starting Music Player Daemon... May 17 08:58:51 stanzetta volumio-remote-updater[565]: [2025-05-17 08:58:51] [connect] Successful connection May 17 08:58:51 stanzetta volumio[886]: info: Preparing to generate the ALSA configuration file May 17 08:58:51 stanzetta sudo[21508]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 17 08:58:51 stanzetta sudo[21508]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:51 stanzetta go-librespot[21479]: time="2025-05-17T08:58:51+02:00" level=debug msg="obtained new client token: AACO55zYuyN5RTtCqm2hBcFrbaHPe5BhkD2Zl07JCr1Ix4VQZG8eWBqyEVdQuq+/x2K0YNv1glm/QXBv2L25h5XkPsA8M/byJHZuCQf7vOA9WycnbPVdvxoTXxDT9SbmC99gKUVhj8S0dVAwkHoT4McMLz3iGOYnczPCkVQlYs9PjZgAoeU6ExeiD2tPhPAs9y6ugkqiDGFgqFtHSXlr4gHFLsdvmQCqaGi30LuKqKT4nDGGa+5V/hG37A==" May 17 08:58:51 stanzetta sudo[21508]: pam_unix(sudo:session): session closed for user root May 17 08:58:51 stanzetta sudo[21503]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 17 08:58:51 stanzetta sudo[21503]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:51 stanzetta sudo[21503]: pam_unix(sudo:session): session closed for user root May 17 08:58:51 stanzetta go-librespot[21479]: time="2025-05-17T08:58:51+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 17 08:58:51 stanzetta sudo[21514]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 17 08:58:51 stanzetta sudo[21514]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:51 stanzetta go-librespot[21479]: time="2025-05-17T08:58:51+02:00" level=debug msg="completed keyexchange" May 17 08:58:51 stanzetta go-librespot[21479]: time="2025-05-17T08:58:51+02:00" level=debug msg="completed challenge" May 17 08:58:51 stanzetta sudo[21514]: pam_unix(sudo:session): session closed for user root May 17 08:58:51 stanzetta go-librespot[21479]: time="2025-05-17T08:58:51+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 17 08:58:51 stanzetta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 08:58:51 stanzetta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 08:58:51 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:51 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:51 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:51 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:51 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:51 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:51 stanzetta sudo[21521]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 17 08:58:51 stanzetta sudo[21521]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:51 stanzetta sudo[21521]: pam_unix(sudo:session): session closed for user root May 17 08:58:51 stanzetta sudo[21524]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 17 08:58:51 stanzetta sudo[21524]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:51 stanzetta volumio[886]: 0+0 records in May 17 08:58:51 stanzetta volumio[886]: 0+0 records out May 17 08:58:51 stanzetta volumio[886]: 0 bytes copied, 0.000185312 s, 0.0 kB/s May 17 08:58:51 stanzetta systemd[1]: Stopping Volumio Qobuz Connect Service... May 17 08:58:51 stanzetta qobuz-connect[21442]: 20250517 08:58:51.680 [21442.21442] INFO SampleApp: Stopping Local configuration server May 17 08:58:51 stanzetta qobuz-connect[21442]: 20250517 08:58:51.691 [21442.21442] INFO SampleApp: shat down connection on UNIX socket May 17 08:58:51 stanzetta systemd[1]: qobuz-connect.service: Succeeded. May 17 08:58:51 stanzetta systemd[1]: Stopped Volumio Qobuz Connect Service. May 17 08:58:51 stanzetta systemd[1]: Started Volumio Qobuz Connect Service. May 17 08:58:51 stanzetta sudo[21524]: pam_unix(sudo:session): session closed for user root May 17 08:58:51 stanzetta volumio[886]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 17 08:58:51 stanzetta volumio[886]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 17 08:58:51 stanzetta volumio[886]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf May 17 08:58:51 stanzetta volumio[886]: info: Reading ALSA contributions from plugins. May 17 08:58:51 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:51 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:51 stanzetta sudo[21536]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 17 08:58:51 stanzetta sudo[21536]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:51 stanzetta volumio[886]: info: MPD Permissions set May 17 08:58:51 stanzetta volumio[886]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 17 08:58:51 stanzetta volumio[886]: info: QobuzConnect: setDeactiveState invoked May 17 08:58:51 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:51 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:51 stanzetta volumio[886]: info: Shairport-Sync Started May 17 08:58:51 stanzetta volumio-remote-updater[565]: [2025-05-17 08:58:51] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1747465131 101 May 17 08:58:51 stanzetta volumio[886]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 13 May 17 08:58:51 stanzetta volumio[886]: info: Executing endpoint qc_getconfig May 17 08:58:51 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 17 08:58:51 stanzetta qobuz-connect[21528]: 20250517 08:58:51.930 [21528.21528] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 17 08:58:51 stanzetta qobuz-connect[21528]: 20250517 08:58:51.938 [21528.21528] INFO VolumeManager: [0xc36a10]: Setting new playback volume: 75 May 17 08:58:51 stanzetta qobuz-connect[21528]: 20250517 08:58:51.938 [21528.21528] INFO VolumeManager: [0xc36a10]: Setting new mute state: 0 May 17 08:58:51 stanzetta qobuz-connect[21528]: 20250517 08:58:51.938 [21528.21528] INFO QobuzConnect: [0xc373e0]: Client initialized! May 17 08:58:51 stanzetta qobuz-connect[21528]: 20250517 08:58:51.938 [21528.21528] INFO SampleApp: Starting Avahi advertising, name: Stanzetta, service name: _qobuz-connect._tcp May 17 08:58:51 stanzetta systemd[1]: Started Volumio Tidal Connect Service. May 17 08:58:51 stanzetta qobuz-connect[21528]: 20250517 08:58:51.963 [21528.21528] INFO LocalConfigManager: [0xc362f0]: Starting Local Configuration server May 17 08:58:51 stanzetta qobuz-connect[21528]: 20250517 08:58:51.965 [21528.21528] INFO SampleApp: Starting Local configuration server May 17 08:58:51 stanzetta qobuz-connect[21528]: 20250517 08:58:51.967 [21528.21528] INFO SampleApp: Connected to UNIX socket client 0xc2bf60 May 17 08:58:51 stanzetta volumio[886]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 17 08:58:51 stanzetta volumio[886]: info: QobuzConnect: QOBUZ Connect daemon connected May 17 08:58:51 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:51 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:51 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:51 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:51 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:51 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:51 stanzetta sudo[21536]: pam_unix(sudo:session): session closed for user root May 17 08:58:51 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:51 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:52 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 17 08:58:52 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:52 stanzetta qobuz-connect[21528]: 20250517 08:58:52.084 [21528.21528] INFO SampleApp: Playback volume changed: 75 May 17 08:58:52 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:52 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:52 stanzetta volumio[886]: info: Starting Shairport Sync May 17 08:58:52 stanzetta volumio[886]: info: Asound.conf file unchanged, so no further update is needed May 17 08:58:52 stanzetta volumio[886]: info: Output device has changed, restarting MPD May 17 08:58:52 stanzetta sudo[21548]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 17 08:58:52 stanzetta sudo[21548]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:52 stanzetta systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 17 08:58:52 stanzetta systemd[1]: shairport-sync.service: Succeeded. May 17 08:58:52 stanzetta systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 17 08:58:52 stanzetta sudo[21551]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 17 08:58:52 stanzetta sudo[21551]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:52 stanzetta volumio[886]: info: Output device has changed, restarting Shairport Sync May 17 08:58:52 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:52 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 17 08:58:52 stanzetta sudo[21555]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 17 08:58:52 stanzetta sudo[21551]: pam_unix(sudo:session): session closed for user root May 17 08:58:52 stanzetta systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 17 08:58:52 stanzetta sudo[21555]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:52 stanzetta sudo[21548]: pam_unix(sudo:session): session closed for user root May 17 08:58:52 stanzetta systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 17 08:58:52 stanzetta systemd[1]: mpd.service: Succeeded. May 17 08:58:52 stanzetta systemd[1]: Stopped Music Player Daemon. May 17 08:58:52 stanzetta systemd[1]: Starting Music Player Daemon... May 17 08:58:52 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:58:52 stanzetta volumio[886]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 17 08:58:52 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:58:52 stanzetta volumio[886]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 17 08:58:52 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:52 stanzetta volumio[886]: info: QobuzConnect: setDeactiveState invoked May 17 08:58:52 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:52 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:52 stanzetta volumio[886]: info: PLUGIN START: fusiondsp May 17 08:58:52 stanzetta volumio[886]: info: Loading i18n strings for locale it May 17 08:58:52 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 17 08:58:52 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:52 stanzetta volumio[886]: info: FusionDsp - mixtype--------------------- Hardware May 17 08:58:52 stanzetta volumio[886]: info: Preparing to generate the ALSA configuration file May 17 08:58:52 stanzetta sudo[21569]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 17 08:58:52 stanzetta sudo[21569]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:52 stanzetta sudo[21564]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 17 08:58:52 stanzetta sudo[21564]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:52 stanzetta sudo[21564]: pam_unix(sudo:session): session closed for user root May 17 08:58:52 stanzetta systemd[1]: Stopping Volumio Tidal Connect Service... May 17 08:58:52 stanzetta systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM May 17 08:58:52 stanzetta systemd[1]: vtcs.service: Succeeded. May 17 08:58:52 stanzetta volumio[886]: info: Done. May 17 08:58:52 stanzetta systemd[1]: Stopped Volumio Tidal Connect Service. May 17 08:58:52 stanzetta sudo[21569]: pam_unix(sudo:session): session closed for user root May 17 08:58:52 stanzetta sudo[21575]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 17 08:58:52 stanzetta sudo[21575]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:52 stanzetta sudo[21575]: pam_unix(sudo:session): session closed for user root May 17 08:58:52 stanzetta volumio[886]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 17 08:58:52 stanzetta volumio[886]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 17 08:58:52 stanzetta volumio[886]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf May 17 08:58:52 stanzetta volumio[886]: info: Reading ALSA contributions from plugins. May 17 08:58:52 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:52 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:52 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:52 stanzetta sudo[21582]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 17 08:58:52 stanzetta sudo[21582]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:52 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:52 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:52 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:52 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:52 stanzetta volumio[886]: verbose: New Socket.io Connection to 192.168.1.4 from 192.168.1.3 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:138.0) Gecko/20100101 Firefox/138.0 Engine version: 3 Transport: polling Total Clients: 14 May 17 08:58:52 stanzetta volumio[886]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined May 17 08:58:52 stanzetta volumio[886]: info: MPD Permissions set May 17 08:58:52 stanzetta sudo[21582]: pam_unix(sudo:session): session closed for user root May 17 08:58:52 stanzetta volumio[886]: info: Shairport-Sync Started May 17 08:58:52 stanzetta sudo[21584]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 17 08:58:52 stanzetta sudo[21584]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:52 stanzetta volumio[886]: info: Executing endpoint tc_getconfig May 17 08:58:52 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 17 08:58:52 stanzetta systemd[1]: Stopping Volumio Qobuz Connect Service... May 17 08:58:52 stanzetta qobuz-connect[21528]: 20250517 08:58:52.983 [21528.21528] INFO SampleApp: Stopping Local configuration server May 17 08:58:52 stanzetta qobuz-connect[21528]: 20250517 08:58:52.983 [21528.21528] INFO SampleApp: shat down connection on UNIX socket May 17 08:58:52 stanzetta systemd[1]: qobuz-connect.service: Succeeded. May 17 08:58:53 stanzetta systemd[1]: Stopped Volumio Qobuz Connect Service. May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 17 08:58:53 stanzetta volumio[886]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:53 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetVisibleSources May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 17 08:58:53 stanzetta systemd[1]: Started Volumio Qobuz Connect Service. May 17 08:58:53 stanzetta sudo[21584]: pam_unix(sudo:session): session closed for user root May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetQueue May 17 08:58:53 stanzetta volumio[886]: info: CoreStateMachine::getQueue May 17 08:58:53 stanzetta volumio[886]: info: CorePlayQueue::getQueue May 17 08:58:53 stanzetta volumio[886]: info: Listing playlists May 17 08:58:53 stanzetta volumio[886]: info: Initializing connection to go-librespot Websocket May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:53 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:53 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:53 stanzetta volumio[886]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 17 08:58:53 stanzetta volumio[886]: info: QobuzConnect: setDeactiveState invoked May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:53 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:53 stanzetta volumio[886]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 08:58:53 stanzetta volumio[886]: info: Executing endpoint qc_getconfig May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 17 08:58:53 stanzetta qobuz-connect[21586]: 20250517 08:58:53.505 [21586.21586] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 17 08:58:53 stanzetta qobuz-connect[21586]: 20250517 08:58:53.512 [21586.21586] INFO VolumeManager: [0x1187a10]: Setting new playback volume: 75 May 17 08:58:53 stanzetta qobuz-connect[21586]: 20250517 08:58:53.512 [21586.21586] INFO VolumeManager: [0x1187a10]: Setting new mute state: 0 May 17 08:58:53 stanzetta qobuz-connect[21586]: 20250517 08:58:53.512 [21586.21586] INFO QobuzConnect: [0x11883e0]: Client initialized! May 17 08:58:53 stanzetta qobuz-connect[21586]: 20250517 08:58:53.512 [21586.21586] INFO SampleApp: Starting Avahi advertising, name: Stanzetta, service name: _qobuz-connect._tcp May 17 08:58:53 stanzetta volumio[886]: info: Starting Shairport Sync May 17 08:58:53 stanzetta qobuz-connect[21586]: 20250517 08:58:53.531 [21586.21586] INFO LocalConfigManager: [0x11872f0]: Starting Local Configuration server May 17 08:58:53 stanzetta qobuz-connect[21586]: 20250517 08:58:53.531 [21586.21586] INFO SampleApp: Starting Local configuration server May 17 08:58:53 stanzetta qobuz-connect[21586]: 20250517 08:58:53.532 [21586.21586] INFO SampleApp: Connected to UNIX socket client 0x117cf60 May 17 08:58:53 stanzetta sudo[21594]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 17 08:58:53 stanzetta sudo[21594]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:53 stanzetta qobuz-connect[21586]: 20250517 08:58:53.656 [21586.21586] INFO SampleApp: Playback volume changed: 75 May 17 08:58:53 stanzetta systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 17 08:58:53 stanzetta systemd[1]: shairport-sync.service: Succeeded. May 17 08:58:53 stanzetta systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 17 08:58:53 stanzetta volumio[886]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 17 08:58:53 stanzetta volumio[886]: info: QobuzConnect: QOBUZ Connect daemon connected May 17 08:58:53 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:53 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:53 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:53 stanzetta volumio[886]: info: Asound.conf file unchanged, so no further update is needed May 17 08:58:53 stanzetta volumio[886]: info: Output device has changed, restarting MPD May 17 08:58:53 stanzetta systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 17 08:58:53 stanzetta sudo[21598]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 17 08:58:53 stanzetta sudo[21598]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:53 stanzetta sudo[21598]: pam_unix(sudo:session): session closed for user root May 17 08:58:53 stanzetta sudo[21594]: pam_unix(sudo:session): session closed for user root May 17 08:58:53 stanzetta volumio[886]: info: Output device has changed, restarting Shairport Sync May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 17 08:58:53 stanzetta sudo[21604]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 17 08:58:53 stanzetta sudo[21604]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:53 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:58:53 stanzetta volumio[886]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 17 08:58:53 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:58:53 stanzetta volumio[886]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:53 stanzetta systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 17 08:58:53 stanzetta systemd[1]: mpd.service: Succeeded. May 17 08:58:53 stanzetta systemd[1]: Stopped Music Player Daemon. May 17 08:58:53 stanzetta volumio[886]: info: QobuzConnect: setDeactiveState invoked May 17 08:58:53 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:53 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:54 stanzetta systemd[1]: Starting Music Player Daemon... May 17 08:58:54 stanzetta volumio[886]: info: Preparing to generate the ALSA configuration file May 17 08:58:54 stanzetta sudo[21627]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 17 08:58:54 stanzetta sudo[21627]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:54 stanzetta sudo[21627]: pam_unix(sudo:session): session closed for user root May 17 08:58:54 stanzetta sudo[21622]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 17 08:58:54 stanzetta sudo[21622]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:54 stanzetta sudo[21622]: pam_unix(sudo:session): session closed for user root May 17 08:58:54 stanzetta sudo[21632]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 17 08:58:54 stanzetta sudo[21632]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:54 stanzetta sudo[21632]: pam_unix(sudo:session): session closed for user root May 17 08:58:54 stanzetta volumio[886]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 17 08:58:54 stanzetta volumio[886]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 17 08:58:54 stanzetta volumio[886]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf May 17 08:58:54 stanzetta volumio[886]: info: Reading ALSA contributions from plugins. May 17 08:58:54 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:54 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:54 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:54 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:54 stanzetta sudo[21640]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 17 08:58:54 stanzetta sudo[21640]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:54 stanzetta volumio[886]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined May 17 08:58:54 stanzetta volumio[886]: info: MPD Permissions set May 17 08:58:54 stanzetta volumio[886]: info: TidalConnect service stoped! May 17 08:58:54 stanzetta volumio[886]: info: Shairport-Sync Started May 17 08:58:54 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:54 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:54 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:54 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:54 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:54 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:54 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:54 stanzetta sudo[21640]: pam_unix(sudo:session): session closed for user root May 17 08:58:54 stanzetta sudo[21642]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 17 08:58:54 stanzetta sudo[21642]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:54 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 17 08:58:54 stanzetta systemd[1]: Stopping Volumio Qobuz Connect Service... May 17 08:58:54 stanzetta qobuz-connect[21586]: 20250517 08:58:54.401 [21586.21586] INFO SampleApp: Stopping Local configuration server May 17 08:58:54 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:54 stanzetta qobuz-connect[21586]: 20250517 08:58:54.411 [21586.21586] INFO SampleApp: shat down connection on UNIX socket May 17 08:58:54 stanzetta systemd[1]: qobuz-connect.service: Succeeded. May 17 08:58:54 stanzetta systemd[1]: Stopped Volumio Qobuz Connect Service. May 17 08:58:54 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:54 stanzetta volumio[886]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 17 08:58:54 stanzetta volumio[886]: info: QobuzConnect: setDeactiveState invoked May 17 08:58:54 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:54 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:54 stanzetta volumio[886]: info: Starting Shairport Sync May 17 08:58:54 stanzetta systemd[1]: Started Volumio Qobuz Connect Service. May 17 08:58:54 stanzetta systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 08:58:54 stanzetta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1019. May 17 08:58:54 stanzetta systemd[1]: Stopped go-librespot Daemon. May 17 08:58:54 stanzetta sudo[21642]: pam_unix(sudo:session): session closed for user root May 17 08:58:54 stanzetta systemd[1]: Started go-librespot Daemon. May 17 08:58:54 stanzetta go-librespot[21650]: go-librespot daemon starting... May 17 08:58:54 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:54 stanzetta volumio[886]: info: TidalConnect service stoped! May 17 08:58:54 stanzetta go-librespot[21650]: time="2025-05-17T08:58:54+02:00" level=info msg="running go-librespot 0.2.0" May 17 08:58:54 stanzetta go-librespot[21650]: time="2025-05-17T08:58:54+02:00" level=debug msg="app state loaded" May 17 08:58:54 stanzetta go-librespot[21650]: time="2025-05-17T08:58:54+02:00" level=debug msg="stored credentials not found" May 17 08:58:54 stanzetta go-librespot[21650]: time="2025-05-17T08:58:54+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 17 08:58:54 stanzetta sudo[21658]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 17 08:58:54 stanzetta sudo[21658]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:54 stanzetta systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 17 08:58:54 stanzetta systemd[1]: shairport-sync.service: Succeeded. May 17 08:58:54 stanzetta systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 17 08:58:54 stanzetta volumio[886]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists May 17 08:58:54 stanzetta volumio[886]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo May 17 08:58:54 stanzetta volumio[886]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists May 17 08:58:54 stanzetta systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 17 08:58:54 stanzetta sudo[21658]: pam_unix(sudo:session): session closed for user root May 17 08:58:54 stanzetta volumio[886]: info: camilladsp service started and running in background, instance 4 May 17 08:58:54 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:54 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:58:54 stanzetta volumio[886]: cannot open device 'volumioHw': Device or resource busy May 17 08:58:54 stanzetta volumio[886]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json May 17 08:58:54 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:58:54 stanzetta volumio[886]: cannot open device 'volumioHw': Device or resource busy May 17 08:58:54 stanzetta volumio[886]: info: FusionDsp loaded May 17 08:58:54 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 17 08:58:54 stanzetta go-librespot[21650]: time="2025-05-17T08:58:54+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 17 08:58:54 stanzetta go-librespot[21650]: time="2025-05-17T08:58:54+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 17 08:58:54 stanzetta go-librespot[21650]: time="2025-05-17T08:58:54+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 17 08:58:54 stanzetta volumio[886]: info: FusionDsp - Reporting Fusion DSP Enabled May 17 08:58:54 stanzetta volumio[886]: info: Adding Signal Path Element [object Object] May 17 08:58:54 stanzetta volumio[886]: info: Updating fusiondspeq DSP Signal Path Element May 17 08:58:54 stanzetta volumio[886]: info: FusionDsp - ---- installed callbackRead May 17 08:58:54 stanzetta volumio[886]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 17 08:58:54 stanzetta go-librespot[21650]: time="2025-05-17T08:58:54+02:00" level=info msg="zeroconf server listening on port 38563" May 17 08:58:54 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:55 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:55 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 17 08:58:55 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate from file: 44100 May 17 08:58:55 stanzetta volumio[886]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 17 08:58:55 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 17 08:58:55 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate from file: 44100 May 17 08:58:55 stanzetta volumio[886]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 17 08:58:55 stanzetta sudo[21685]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service May 17 08:58:55 stanzetta sudo[21685]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:55 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 17 08:58:55 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate from file: 44100 May 17 08:58:55 stanzetta volumio[886]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 17 08:58:55 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 17 08:58:55 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate from file: 44100 May 17 08:58:55 stanzetta volumio[886]: info: camilladsp stopping service pid 21671... May 17 08:58:55 stanzetta sudo[21685]: pam_unix(sudo:session): session closed for user root May 17 08:58:55 stanzetta volumio[886]: info: camilladsp service terminated, instance 4 May 17 08:58:55 stanzetta volumio[886]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 17 08:58:55 stanzetta volumio[886]: info: camilladsp service started and running in background, instance 4 May 17 08:58:55 stanzetta go-librespot[21650]: time="2025-05-17T08:58:55+02:00" level=debug msg="obtained new client token: AACvPdgBk8YvjLuKYWyfUyLhAYeeUWMVutYF6JyyhqbVNHJbJEG/TjpjpY94lSQwAYwcyfqcOgmYM5qq5DbcTANT/d9GKDeMfJsh/SIRDBqTN1XrhBnyle1KtIMPn0rCxsS2WlCfUA+IEsWwMEhZ3aE8+9OQSfIY6Not5Fci6OT9mQ73OdwcCzBRYcjALNMlaNk9Ih+giRYo60bVwORV0rljnwelMhYYnoEBeFVcSmyjyXEeOmVSbwDtSQ==" May 17 08:58:55 stanzetta volumio[886]: info: Shairport-Sync Started May 17 08:58:55 stanzetta volumio[886]: info: Asound.conf file unchanged, so no further update is needed May 17 08:58:55 stanzetta volumio[886]: info: Output device has changed, restarting MPD May 17 08:58:55 stanzetta go-librespot[21650]: time="2025-05-17T08:58:55+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 17 08:58:55 stanzetta sudo[21702]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 17 08:58:55 stanzetta sudo[21702]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:55 stanzetta sudo[21702]: pam_unix(sudo:session): session closed for user root May 17 08:58:55 stanzetta volumio[886]: info: Output device has changed, restarting Shairport Sync May 17 08:58:55 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:55 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 17 08:58:55 stanzetta sudo[21705]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 17 08:58:55 stanzetta sudo[21705]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:55 stanzetta systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 17 08:58:55 stanzetta systemd[1]: mpd.service: Succeeded. May 17 08:58:55 stanzetta systemd[1]: Stopped Music Player Daemon. May 17 08:58:55 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:58:55 stanzetta volumio[886]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 17 08:58:55 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:58:55 stanzetta volumio[886]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 17 08:58:55 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:55 stanzetta volumio[886]: info: QobuzConnect: setDeactiveState invoked May 17 08:58:55 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:55 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:55 stanzetta systemd[1]: Starting Music Player Daemon... May 17 08:58:55 stanzetta sudo[21714]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 17 08:58:55 stanzetta sudo[21714]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:55 stanzetta sudo[21714]: pam_unix(sudo:session): session closed for user root May 17 08:58:55 stanzetta sudo[21717]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 17 08:58:55 stanzetta sudo[21717]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:55 stanzetta sudo[21710]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 17 08:58:55 stanzetta sudo[21710]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:55 stanzetta sudo[21710]: pam_unix(sudo:session): session closed for user root May 17 08:58:55 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:55 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:55 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:55 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:55 stanzetta volumio[886]: info: Executing endpoint qc_getconfig May 17 08:58:55 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 17 08:58:55 stanzetta volumio[886]: verbose: New Socket.io Connection to 192.168.1.4:3000 from 192.168.1.5 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 May 17 08:58:55 stanzetta volumio[886]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 17 08:58:55 stanzetta volumio[886]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 17 08:58:55 stanzetta volumio[886]: info: TidalConnect service started! May 17 08:58:55 stanzetta qobuz-connect[21648]: 20250517 08:58:55.748 [21648.21648] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 17 08:58:55 stanzetta qobuz-connect[21648]: 20250517 08:58:55.755 [21648.21648] INFO VolumeManager: [0x8e0a10]: Setting new playback volume: 75 May 17 08:58:55 stanzetta qobuz-connect[21648]: 20250517 08:58:55.755 [21648.21648] INFO VolumeManager: [0x8e0a10]: Setting new mute state: 0 May 17 08:58:55 stanzetta qobuz-connect[21648]: 20250517 08:58:55.755 [21648.21648] INFO QobuzConnect: [0x8e13e0]: Client initialized! May 17 08:58:55 stanzetta qobuz-connect[21648]: 20250517 08:58:55.755 [21648.21648] INFO SampleApp: Starting Avahi advertising, name: Stanzetta, service name: _qobuz-connect._tcp May 17 08:58:55 stanzetta sudo[21727]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 17 08:58:55 stanzetta sudo[21727]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:55 stanzetta qobuz-connect[21648]: 20250517 08:58:55.817 [21648.21648] INFO LocalConfigManager: [0x8e02f0]: Starting Local Configuration server May 17 08:58:55 stanzetta qobuz-connect[21648]: 20250517 08:58:55.817 [21648.21648] INFO SampleApp: Starting Local configuration server May 17 08:58:55 stanzetta qobuz-connect[21648]: 20250517 08:58:55.818 [21648.21648] INFO SampleApp: Connected to UNIX socket client 0x8d5f60 May 17 08:58:55 stanzetta sudo[21727]: pam_unix(sudo:session): session closed for user root May 17 08:58:55 stanzetta sudo[21717]: pam_unix(sudo:session): session closed for user root May 17 08:58:55 stanzetta volumio[886]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 16 May 17 08:58:55 stanzetta volumio[886]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 17 08:58:55 stanzetta volumio[886]: info: QobuzConnect: QOBUZ Connect daemon connected May 17 08:58:55 stanzetta volumio[886]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined May 17 08:58:55 stanzetta volumio[886]: info: MPD Permissions set May 17 08:58:55 stanzetta volumio[886]: info: TidalConnect service stoped! May 17 08:58:55 stanzetta volumio[886]: info: MRS: Adding multiroomSync output May 17 08:58:55 stanzetta sudo[21734]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 17 08:58:55 stanzetta volumio[886]: info: Adding audio output: May 17 08:58:55 stanzetta sudo[21734]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:55 stanzetta volumio[886]: info: MRS: Pushing multiroomSync output May 17 08:58:55 stanzetta volumio[886]: info: TidalConnect service stoped! May 17 08:58:55 stanzetta qobuz-connect[21648]: 20250517 08:58:55.896 [21648.21648] INFO SampleApp: Stopping Local configuration server May 17 08:58:55 stanzetta systemd[1]: Stopping Volumio Qobuz Connect Service... May 17 08:58:55 stanzetta qobuz-connect[21648]: 20250517 08:58:55.907 [21648.21648] INFO SampleApp: shat down connection on UNIX socket May 17 08:58:55 stanzetta systemd[1]: qobuz-connect.service: Succeeded. May 17 08:58:55 stanzetta systemd[1]: Stopped Volumio Qobuz Connect Service. May 17 08:58:55 stanzetta go-librespot[21650]: time="2025-05-17T08:58:55+02:00" level=debug msg="completed keyexchange" May 17 08:58:55 stanzetta go-librespot[21650]: time="2025-05-17T08:58:55+02:00" level=debug msg="completed challenge" May 17 08:58:55 stanzetta systemd[1]: Started Volumio Qobuz Connect Service. May 17 08:58:56 stanzetta sudo[21734]: pam_unix(sudo:session): session closed for user root May 17 08:58:56 stanzetta go-librespot[21650]: time="2025-05-17T08:58:56+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 17 08:58:56 stanzetta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 08:58:56 stanzetta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 08:58:56 stanzetta volumio[886]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 17 08:58:56 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:56 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:56 stanzetta sudo[21750]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 17 08:58:56 stanzetta sudo[21750]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket May 17 08:58:56 stanzetta volumio[886]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 17 08:58:56 stanzetta volumio[886]: info: QobuzConnect: setDeactiveState invoked May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:56 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:56 stanzetta systemd[1]: Started Volumio Tidal Connect Service. May 17 08:58:56 stanzetta sudo[21750]: pam_unix(sudo:session): session closed for user root May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:58:56 stanzetta volumio[886]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 17 08:58:56 stanzetta volumio[886]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 17 08:58:56 stanzetta volumio[886]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 17 08:58:56 stanzetta volumio[886]: info: Executing endpoint qc_getconfig May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 17 08:58:56 stanzetta qobuz-connect[21737]: 20250517 08:58:56.275 [21737.21737] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:56 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:56 stanzetta volumio[886]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 17 08:58:56 stanzetta volumio[886]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 17 08:58:56 stanzetta qobuz-connect[21737]: 20250517 08:58:56.292 [21737.21737] INFO VolumeManager: [0x6caa10]: Setting new playback volume: 75 May 17 08:58:56 stanzetta qobuz-connect[21737]: 20250517 08:58:56.292 [21737.21737] INFO VolumeManager: [0x6caa10]: Setting new mute state: 0 May 17 08:58:56 stanzetta qobuz-connect[21737]: 20250517 08:58:56.292 [21737.21737] INFO QobuzConnect: [0x6cb3e0]: Client initialized! May 17 08:58:56 stanzetta qobuz-connect[21737]: 20250517 08:58:56.293 [21737.21737] INFO SampleApp: Starting Avahi advertising, name: Stanzetta, service name: _qobuz-connect._tcp May 17 08:58:56 stanzetta qobuz-connect[21737]: 20250517 08:58:56.322 [21737.21737] INFO LocalConfigManager: [0x6ca2f0]: Starting Local Configuration server May 17 08:58:56 stanzetta qobuz-connect[21737]: 20250517 08:58:56.322 [21737.21737] INFO SampleApp: Starting Local configuration server May 17 08:58:56 stanzetta qobuz-connect[21737]: 20250517 08:58:56.323 [21737.21737] INFO SampleApp: Connected to UNIX socket client 0x6bff60 May 17 08:58:56 stanzetta volumio[886]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 17 08:58:56 stanzetta volumio[886]: info: QobuzConnect: QOBUZ Connect daemon connected May 17 08:58:56 stanzetta volumio[886]: info: Starting Shairport Sync May 17 08:58:56 stanzetta qobuz-connect[21737]: 20250517 08:58:56.424 [21737.21737] INFO SampleApp: Playback volume changed: 75 May 17 08:58:56 stanzetta sudo[21772]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 17 08:58:56 stanzetta sudo[21772]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:56 stanzetta systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 17 08:58:56 stanzetta systemd[1]: shairport-sync.service: Succeeded. May 17 08:58:56 stanzetta systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:56 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:56 stanzetta volumio[886]: info: Initializing connection to go-librespot Websocket May 17 08:58:56 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:58:56 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:58:56 stanzetta systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 17 08:58:56 stanzetta sudo[21777]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 17 08:58:56 stanzetta sudo[21777]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:56 stanzetta volumio[886]: info: Executing endpoint tc_getconfig May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 17 08:58:56 stanzetta sudo[21772]: pam_unix(sudo:session): session closed for user root May 17 08:58:56 stanzetta vtcs[21753]: STARTING TidalConnect services, version: 1.4.0.34 May 17 08:58:56 stanzetta sudo[21777]: pam_unix(sudo:session): session closed for user root May 17 08:58:56 stanzetta volumio[886]: info: Shairport-Sync Started May 17 08:58:56 stanzetta volumio[886]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 08:58:56 stanzetta vtcs[21753]: STARTED TidalConnect services. May 17 08:58:56 stanzetta volumio[886]: info: Executing endpoint tc_connect May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect May 17 08:58:56 stanzetta volumio[886]: info: Connecting to TidalConnect May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::servicePushState May 17 08:58:56 stanzetta volumio[886]: info: CoreStateMachine::pushState May 17 08:58:56 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::volumioPushState May 17 08:58:56 stanzetta volumio[886]: info: MRS: Pushing multiroomSync output update for this device May 17 08:58:56 stanzetta volumio[886]: info: MRS: Pushing multiroomSync output May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:56 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:56 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:56 stanzetta volumio[886]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::servicePushState May 17 08:58:56 stanzetta volumio[886]: info: CoreStateMachine::pushState May 17 08:58:56 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::volumioPushState May 17 08:58:56 stanzetta volumio[886]: info: MRS: Pushing multiroomSync output update for this device May 17 08:58:56 stanzetta volumio[886]: info: MRS: Pushing multiroomSync output May 17 08:58:56 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:56 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:56 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:56 stanzetta volumio[886]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect May 17 08:58:56 stanzetta volumio[886]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 17 08:58:56 stanzetta volumio[886]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 17 08:58:57 stanzetta volumio[886]: info: TidalConnect service stoped! May 17 08:58:57 stanzetta volumio[886]: info: TidalConnect service stoped! May 17 08:58:57 stanzetta volumio[886]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 17 08:58:57 stanzetta volumio[886]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 17 08:58:57 stanzetta sudo[21855]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 17 08:58:57 stanzetta sudo[21855]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:57 stanzetta sudo[21855]: pam_unix(sudo:session): session closed for user root May 17 08:58:57 stanzetta mpd[21725]: May 17 08:58 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 17 08:58:57 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 17 08:58:58 stanzetta systemd[1]: Started Music Player Daemon. May 17 08:58:58 stanzetta sudo[21555]: pam_unix(sudo:session): session closed for user root May 17 08:58:58 stanzetta sudo[21604]: pam_unix(sudo:session): session closed for user root May 17 08:58:58 stanzetta sudo[21705]: pam_unix(sudo:session): session closed for user root May 17 08:58:58 stanzetta sudo[21497]: pam_unix(sudo:session): session closed for user root May 17 08:58:58 stanzetta sudo[21308]: pam_unix(sudo:session): session closed for user root May 17 08:58:58 stanzetta systemd[1]: Started MPD OLED Plugin. May 17 08:58:58 stanzetta volumio[886]: error: MPD error: The expression evaluated to a falsy value: May 17 08:58:58 stanzetta volumio[886]: assert.ok(self.idling) May 17 08:58:58 stanzetta volumio[886]: error: The expression evaluated to a falsy value: May 17 08:58:58 stanzetta volumio[886]: assert.ok(self.idling) May 17 08:58:58 stanzetta volumio[886]: error: MPD error: The expression evaluated to a falsy value: May 17 08:58:58 stanzetta volumio[886]: assert.ok(self.idling) May 17 08:58:58 stanzetta volumio[886]: error: The expression evaluated to a falsy value: May 17 08:58:58 stanzetta volumio[886]: assert.ok(self.idling) May 17 08:58:58 stanzetta volumio[886]: error: MPD error: The expression evaluated to a falsy value: May 17 08:58:58 stanzetta volumio[886]: assert.ok(self.idling) May 17 08:58:58 stanzetta volumio[886]: error: The expression evaluated to a falsy value: May 17 08:58:58 stanzetta volumio[886]: assert.ok(self.idling) May 17 08:58:58 stanzetta volumio[886]: error: MPD error: The expression evaluated to a falsy value: May 17 08:58:58 stanzetta volumio[886]: assert.ok(self.idling) May 17 08:58:58 stanzetta volumio[886]: error: The expression evaluated to a falsy value: May 17 08:58:58 stanzetta volumio[886]: assert.ok(self.idling) May 17 08:58:58 stanzetta volumio[886]: error: updateQueue error: null May 17 08:58:58 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:58 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:58 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:58 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:58 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:58 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:58 stanzetta volumio[886]: info: TidalConnect service stoped! May 17 08:58:58 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:58 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:58 stanzetta volumio[886]: info: TidalConnect service stoped! May 17 08:58:58 stanzetta volumio[886]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 17 08:58:58 stanzetta volumio[886]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 17 08:58:59 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:59 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:59 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:59 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:59 stanzetta systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 08:58:59 stanzetta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1020. May 17 08:58:59 stanzetta systemd[1]: Stopped go-librespot Daemon. May 17 08:58:59 stanzetta sudo[21992]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 17 08:58:59 stanzetta sudo[21992]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:58:59 stanzetta systemd[1]: Started go-librespot Daemon. May 17 08:58:59 stanzetta go-librespot[21993]: go-librespot daemon starting... May 17 08:58:59 stanzetta go-librespot[21993]: time="2025-05-17T08:58:59+02:00" level=info msg="running go-librespot 0.2.0" May 17 08:58:59 stanzetta go-librespot[21993]: time="2025-05-17T08:58:59+02:00" level=debug msg="app state loaded" May 17 08:58:59 stanzetta go-librespot[21993]: time="2025-05-17T08:58:59+02:00" level=debug msg="stored credentials not found" May 17 08:58:59 stanzetta go-librespot[21993]: time="2025-05-17T08:58:59+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 17 08:58:59 stanzetta sudo[21992]: pam_unix(sudo:session): session closed for user root May 17 08:58:59 stanzetta volumio[886]: info: TidalConnect service started! May 17 08:58:59 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:59 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:59 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:59 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:59 stanzetta go-librespot[21993]: time="2025-05-17T08:58:59+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 17 08:58:59 stanzetta go-librespot[21993]: time="2025-05-17T08:58:59+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 17 08:58:59 stanzetta go-librespot[21993]: time="2025-05-17T08:58:59+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 17 08:58:59 stanzetta go-librespot[21993]: time="2025-05-17T08:58:59+02:00" level=info msg="zeroconf server listening on port 35795" May 17 08:58:59 stanzetta volumio[886]: info: TidalConnect service started! May 17 08:58:59 stanzetta go-librespot[21993]: time="2025-05-17T08:58:59+02:00" level=debug msg="obtained new client token: AAC1HHQczz+Rpra3rlbw8eGbREowKeZstkKDupS5AVugEPJDDidNYwHgUGFLSy9f8DlK7Xm68ybntsvi3rrwb+nZBz4u8wchzAQydzsLLBfuHJQe2l8U/vRm32nAW7HEQ+UriWJRmgHs8WmfI3I/GQ4ovM9UnloMoGNgceUPHwoD2ASXDJtuJRFwzwRY7HvZKWUBAdAEx52gQi/BtktWe21luHQjqhbQrpVfApCCRtzCLyRomqVZcz9IQ3Qh" May 17 08:58:59 stanzetta volumio[886]: info: Initializing connection to go-librespot Websocket May 17 08:58:59 stanzetta go-librespot[21993]: time="2025-05-17T08:58:59+02:00" level=debug msg="new websocket client" May 17 08:58:59 stanzetta volumio[886]: info: Connection to go-librespot Websocket established May 17 08:58:59 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:59 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:59 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:58:59 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:58:59 stanzetta go-librespot[21993]: time="2025-05-17T08:58:59+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 17 08:58:59 stanzetta go-librespot[21993]: time="2025-05-17T08:58:59+02:00" level=debug msg="completed keyexchange" May 17 08:58:59 stanzetta go-librespot[21993]: time="2025-05-17T08:58:59+02:00" level=debug msg="completed challenge" May 17 08:58:59 stanzetta go-librespot[21993]: time="2025-05-17T08:58:59+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 17 08:58:59 stanzetta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 08:58:59 stanzetta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 08:58:59 stanzetta volumio[886]: info: Connection to go-librespot Websocket closed May 17 08:59:00 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:00 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:00 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:00 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:00 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:00 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:00 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:00 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:00 stanzetta volumio[886]: info: TidalConnect service started! May 17 08:59:00 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:00 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:00 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:00 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:01 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:01 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:01 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:01 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:01 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:01 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:01 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:01 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:01 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:01 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:01 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:01 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:02 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:02 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:02 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:02 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:02 stanzetta volumio[886]: info: TidalConnect service started! May 17 08:59:02 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:02 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:02 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:02 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:02 stanzetta volumio[886]: info: Getting Spotify volume May 17 08:59:02 stanzetta volumio[886]: (node:886) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 08:59:02 stanzetta volumio[886]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) May 17 08:59:02 stanzetta volumio[886]: (node:886) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 95) May 17 08:59:02 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:02 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:02 stanzetta volumio[886]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 17 May 17 08:59:02 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:02 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:02 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:02 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:02 stanzetta volumio[886]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 17 08:59:02 stanzetta volumio[886]: info: Initializing connection to go-librespot Websocket May 17 08:59:02 stanzetta volumio[886]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 08:59:03 stanzetta systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 08:59:03 stanzetta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1021. May 17 08:59:03 stanzetta systemd[1]: Stopped go-librespot Daemon. May 17 08:59:03 stanzetta systemd[1]: Started go-librespot Daemon. May 17 08:59:03 stanzetta go-librespot[22332]: go-librespot daemon starting... May 17 08:59:03 stanzetta go-librespot[22332]: time="2025-05-17T08:59:03+02:00" level=info msg="running go-librespot 0.2.0" May 17 08:59:03 stanzetta go-librespot[22332]: time="2025-05-17T08:59:03+02:00" level=debug msg="app state loaded" May 17 08:59:03 stanzetta go-librespot[22332]: time="2025-05-17T08:59:03+02:00" level=debug msg="stored credentials not found" May 17 08:59:03 stanzetta go-librespot[22332]: time="2025-05-17T08:59:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 17 08:59:03 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:03 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:03 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:03 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:03 stanzetta go-librespot[22332]: time="2025-05-17T08:59:03+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 17 08:59:03 stanzetta go-librespot[22332]: time="2025-05-17T08:59:03+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 17 08:59:03 stanzetta go-librespot[22332]: time="2025-05-17T08:59:03+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 17 08:59:03 stanzetta go-librespot[22332]: time="2025-05-17T08:59:03+02:00" level=info msg="zeroconf server listening on port 45855" May 17 08:59:03 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:03 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:03 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:03 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:03 stanzetta go-librespot[22332]: time="2025-05-17T08:59:03+02:00" level=debug msg="obtained new client token: AABe8kjnUnpxyYXhZM0BCHfh4LTmwvKeQEcRNKznry9rT1K/BS0oay3h3Spugq7MbGb3ZQBPa95AWeLc8kKpwnVzaz2TxYG5izuc0G6buUJgQCq1TUQM9ZkPBcEGPTchpsMk2RfY9OToJdyuRJdKNfJ0EJvbRIMtKHhdgxQ6H2jAWoJWR6N49j9mMJhd7USy2syaPdY3RImUKzpODo3/tkBT5LyNhsDRmksoSg1I76j83SKKwmwwVNxU6Kbv" May 17 08:59:03 stanzetta go-librespot[22332]: time="2025-05-17T08:59:03+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 17 08:59:03 stanzetta go-librespot[22332]: time="2025-05-17T08:59:03+02:00" level=debug msg="completed keyexchange" May 17 08:59:03 stanzetta go-librespot[22332]: time="2025-05-17T08:59:03+02:00" level=debug msg="completed challenge" May 17 08:59:03 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:03 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:03 stanzetta go-librespot[22332]: time="2025-05-17T08:59:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 17 08:59:03 stanzetta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 08:59:03 stanzetta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 08:59:04 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:04 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:04 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:04 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:04 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:04 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:04 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:04 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:04 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:04 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:04 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:04 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:04 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:04 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:05 stanzetta volumio[886]: info: Enabling plugin fusiondsp May 17 08:59:05 stanzetta volumio[886]: info: Loading plugin "fusiondsp"... May 17 08:59:05 stanzetta volumio[886]: info: Applying required configuration parameters for plugin fusiondsp May 17 08:59:05 stanzetta volumio[886]: info: Preparing to generate the ALSA configuration file May 17 08:59:05 stanzetta volumio[886]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 17 08:59:05 stanzetta volumio[886]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 17 08:59:05 stanzetta volumio[886]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf May 17 08:59:05 stanzetta volumio[886]: info: Reading ALSA contributions from plugins. May 17 08:59:05 stanzetta volumio[886]: info: Asound.conf file unchanged, so no further update is needed May 17 08:59:05 stanzetta volumio[886]: info: Output device has changed, restarting MPD May 17 08:59:05 stanzetta sudo[22553]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 17 08:59:05 stanzetta sudo[22553]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:05 stanzetta sudo[22553]: pam_unix(sudo:session): session closed for user root May 17 08:59:05 stanzetta volumio[886]: info: Output device has changed, restarting Shairport Sync May 17 08:59:05 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:05 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 17 08:59:05 stanzetta sudo[22558]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 17 08:59:05 stanzetta sudo[22558]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:05 stanzetta systemd[1]: Stopping MPD OLED Plugin... May 17 08:59:05 stanzetta systemd[1]: mpd_oled_plugin.service: Main process exited, code=killed, status=15/TERM May 17 08:59:05 stanzetta systemd[1]: mpd_oled_plugin.service: Succeeded. May 17 08:59:05 stanzetta systemd[1]: Stopped MPD OLED Plugin. May 17 08:59:05 stanzetta systemd[1]: Stopping Music Player Daemon... May 17 08:59:05 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:59:05 stanzetta volumio[886]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 17 08:59:05 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:59:05 stanzetta volumio[886]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 17 08:59:05 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:05 stanzetta volumio[886]: info: QobuzConnect: setDeactiveState invoked May 17 08:59:05 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:05 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:05 stanzetta vtcs[21753]: [2025-05-17 08:59:05.498] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE May 17 08:59:05 stanzetta vtcs[21753]: [2025-05-17 08:59:05.498] [tisoc] [error] [SpkconServer.cpp:473] socket write error. fd=3 errorno=32 error=Broken pipe May 17 08:59:05 stanzetta vtcs[21753]: [2025-05-17 08:59:05.506] [tisoc] [error] [SpkconServer.cpp:376] recv error. socket disconnected May 17 08:59:05 stanzetta volumio[886]: info: PLUGIN START: fusiondsp May 17 08:59:05 stanzetta systemd[1]: mpd.service: Succeeded. May 17 08:59:05 stanzetta systemd[1]: Stopped Music Player Daemon. May 17 08:59:05 stanzetta volumio[886]: info: Loading i18n strings for locale it May 17 08:59:05 stanzetta sudo[22566]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 17 08:59:05 stanzetta sudo[22566]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:05 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 17 08:59:05 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:05 stanzetta volumio[886]: info: FusionDsp - mixtype--------------------- Hardware May 17 08:59:05 stanzetta volumio[886]: info: Preparing to generate the ALSA configuration file May 17 08:59:05 stanzetta volumio[886]: info: Done. May 17 08:59:05 stanzetta systemd[1]: Starting Music Player Daemon... May 17 08:59:05 stanzetta systemd[1]: Stopping Volumio Tidal Connect Service... May 17 08:59:05 stanzetta systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM May 17 08:59:05 stanzetta systemd[1]: vtcs.service: Succeeded. May 17 08:59:05 stanzetta systemd[1]: Stopped Volumio Tidal Connect Service. May 17 08:59:05 stanzetta sudo[22566]: pam_unix(sudo:session): session closed for user root May 17 08:59:05 stanzetta sudo[22571]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 17 08:59:05 stanzetta sudo[22571]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:05 stanzetta sudo[22571]: pam_unix(sudo:session): session closed for user root May 17 08:59:05 stanzetta sudo[22567]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 17 08:59:05 stanzetta sudo[22567]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:05 stanzetta sudo[22567]: pam_unix(sudo:session): session closed for user root May 17 08:59:05 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:05 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:05 stanzetta volumio[886]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 17 08:59:05 stanzetta volumio[886]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 17 08:59:05 stanzetta volumio[886]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf May 17 08:59:05 stanzetta volumio[886]: info: Reading ALSA contributions from plugins. May 17 08:59:05 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:59:05 stanzetta sudo[22580]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 17 08:59:05 stanzetta sudo[22580]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:05 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:59:05 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:59:05 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:59:05 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:59:05 stanzetta volumio[886]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined May 17 08:59:05 stanzetta volumio[886]: info: MPD Permissions set May 17 08:59:05 stanzetta sudo[22580]: pam_unix(sudo:session): session closed for user root May 17 08:59:05 stanzetta sudo[22583]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 17 08:59:05 stanzetta sudo[22583]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:05 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:05 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:05 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:05 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:05 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:05 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:05 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:05 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:05 stanzetta systemd[1]: Stopping Volumio Qobuz Connect Service... May 17 08:59:05 stanzetta qobuz-connect[21737]: 20250517 08:59:05.978 [21737.21737] INFO SampleApp: Stopping Local configuration server May 17 08:59:05 stanzetta qobuz-connect[21737]: 20250517 08:59:05.989 [21737.21737] INFO SampleApp: shat down connection on UNIX socket May 17 08:59:05 stanzetta systemd[1]: qobuz-connect.service: Succeeded. May 17 08:59:05 stanzetta systemd[1]: Stopped Volumio Qobuz Connect Service. May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:06 stanzetta systemd[1]: Started Volumio Qobuz Connect Service. May 17 08:59:06 stanzetta sudo[22583]: pam_unix(sudo:session): session closed for user root May 17 08:59:06 stanzetta volumio[886]: info: Initializing connection to go-librespot Websocket May 17 08:59:06 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:59:06 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:59:06 stanzetta volumio[886]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 17 08:59:06 stanzetta volumio[886]: info: QobuzConnect: setDeactiveState invoked May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:06 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:06 stanzetta volumio[886]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 08:59:06 stanzetta volumio[886]: info: Starting Shairport Sync May 17 08:59:06 stanzetta volumio[886]: info: Executing endpoint qc_getconfig May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 17 08:59:06 stanzetta qobuz-connect[22595]: 20250517 08:59:06.175 [22595.22595] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 17 08:59:06 stanzetta sudo[22605]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 17 08:59:06 stanzetta sudo[22605]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:06 stanzetta qobuz-connect[22595]: 20250517 08:59:06.182 [22595.22595] INFO VolumeManager: [0xaa2a10]: Setting new playback volume: 75 May 17 08:59:06 stanzetta qobuz-connect[22595]: 20250517 08:59:06.182 [22595.22595] INFO VolumeManager: [0xaa2a10]: Setting new mute state: 0 May 17 08:59:06 stanzetta qobuz-connect[22595]: 20250517 08:59:06.182 [22595.22595] INFO QobuzConnect: [0xaa33e0]: Client initialized! May 17 08:59:06 stanzetta qobuz-connect[22595]: 20250517 08:59:06.182 [22595.22595] INFO SampleApp: Starting Avahi advertising, name: Stanzetta, service name: _qobuz-connect._tcp May 17 08:59:06 stanzetta volumio[886]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 17 08:59:06 stanzetta volumio[886]: info: QobuzConnect: QOBUZ Connect daemon connected May 17 08:59:06 stanzetta volumio[886]: info: Asound.conf file unchanged, so no further update is needed May 17 08:59:06 stanzetta volumio[886]: info: Output device has changed, restarting MPD May 17 08:59:06 stanzetta qobuz-connect[22595]: 20250517 08:59:06.210 [22595.22595] INFO LocalConfigManager: [0xaa22f0]: Starting Local Configuration server May 17 08:59:06 stanzetta qobuz-connect[22595]: 20250517 08:59:06.211 [22595.22595] INFO SampleApp: Starting Local configuration server May 17 08:59:06 stanzetta qobuz-connect[22595]: 20250517 08:59:06.211 [22595.22595] INFO SampleApp: Connected to UNIX socket client 0xa97f60 May 17 08:59:06 stanzetta systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 17 08:59:06 stanzetta systemd[1]: shairport-sync.service: Succeeded. May 17 08:59:06 stanzetta systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 17 08:59:06 stanzetta sudo[22610]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 17 08:59:06 stanzetta systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 17 08:59:06 stanzetta sudo[22605]: pam_unix(sudo:session): session closed for user root May 17 08:59:06 stanzetta sudo[22610]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:06 stanzetta sudo[22610]: pam_unix(sudo:session): session closed for user root May 17 08:59:06 stanzetta qobuz-connect[22595]: 20250517 08:59:06.328 [22595.22595] INFO SampleApp: Playback volume changed: 75 May 17 08:59:06 stanzetta volumio[886]: info: Output device has changed, restarting Shairport Sync May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 17 08:59:06 stanzetta sudo[22613]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 17 08:59:06 stanzetta sudo[22613]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:06 stanzetta systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 17 08:59:06 stanzetta systemd[1]: mpd.service: Succeeded. May 17 08:59:06 stanzetta systemd[1]: Stopped Music Player Daemon. May 17 08:59:06 stanzetta systemd[1]: Starting Music Player Daemon... May 17 08:59:06 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:59:06 stanzetta volumio[886]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 17 08:59:06 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:59:06 stanzetta volumio[886]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:06 stanzetta volumio[886]: info: QobuzConnect: setDeactiveState invoked May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:06 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:06 stanzetta sudo[22620]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 17 08:59:06 stanzetta sudo[22620]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:06 stanzetta sudo[22624]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 17 08:59:06 stanzetta sudo[22620]: pam_unix(sudo:session): session closed for user root May 17 08:59:06 stanzetta sudo[22624]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:06 stanzetta sudo[22629]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 17 08:59:06 stanzetta sudo[22629]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:06 stanzetta sudo[22624]: pam_unix(sudo:session): session closed for user root May 17 08:59:06 stanzetta sudo[22629]: pam_unix(sudo:session): session closed for user root May 17 08:59:06 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:59:06 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:59:06 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:59:06 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:59:06 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:59:06 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:59:06 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:59:06 stanzetta sudo[22639]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 17 08:59:06 stanzetta sudo[22639]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:06 stanzetta sudo[22639]: pam_unix(sudo:session): session closed for user root May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:06 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:06 stanzetta volumio[886]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined May 17 08:59:06 stanzetta volumio[886]: info: MPD Permissions set May 17 08:59:06 stanzetta volumio[886]: info: Shairport-Sync Started May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:06 stanzetta sudo[22642]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 17 08:59:06 stanzetta sudo[22642]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:06 stanzetta systemd[1]: Stopping Volumio Qobuz Connect Service... May 17 08:59:06 stanzetta qobuz-connect[22595]: 20250517 08:59:06.913 [22595.22595] INFO SampleApp: Stopping Local configuration server May 17 08:59:06 stanzetta qobuz-connect[22595]: 20250517 08:59:06.924 [22595.22595] INFO SampleApp: shat down connection on UNIX socket May 17 08:59:06 stanzetta systemd[1]: qobuz-connect.service: Succeeded. May 17 08:59:06 stanzetta systemd[1]: Stopped Volumio Qobuz Connect Service. May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:06 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:59:06 stanzetta volumio[886]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 17 08:59:06 stanzetta volumio[886]: info: QobuzConnect: setDeactiveState invoked May 17 08:59:06 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:06 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:06 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:59:07 stanzetta volumio[886]: info: Starting Shairport Sync May 17 08:59:07 stanzetta systemd[1]: Started Volumio Qobuz Connect Service. May 17 08:59:07 stanzetta sudo[22642]: pam_unix(sudo:session): session closed for user root May 17 08:59:07 stanzetta systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 08:59:07 stanzetta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1022. May 17 08:59:07 stanzetta systemd[1]: Stopped go-librespot Daemon. May 17 08:59:07 stanzetta systemd[1]: Started go-librespot Daemon. May 17 08:59:07 stanzetta go-librespot[22664]: go-librespot daemon starting... May 17 08:59:07 stanzetta go-librespot[22664]: time="2025-05-17T08:59:07+02:00" level=info msg="running go-librespot 0.2.0" May 17 08:59:07 stanzetta go-librespot[22664]: time="2025-05-17T08:59:07+02:00" level=debug msg="app state loaded" May 17 08:59:07 stanzetta go-librespot[22664]: time="2025-05-17T08:59:07+02:00" level=debug msg="stored credentials not found" May 17 08:59:07 stanzetta go-librespot[22664]: time="2025-05-17T08:59:07+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 17 08:59:07 stanzetta volumio[886]: info: Executing endpoint qc_getconfig May 17 08:59:07 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 17 08:59:07 stanzetta qobuz-connect[22654]: 20250517 08:59:07.125 [22654.22654] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 17 08:59:07 stanzetta qobuz-connect[22654]: 20250517 08:59:07.132 [22654.22654] INFO VolumeManager: [0x1346a10]: Setting new playback volume: 75 May 17 08:59:07 stanzetta qobuz-connect[22654]: 20250517 08:59:07.132 [22654.22654] INFO VolumeManager: [0x1346a10]: Setting new mute state: 0 May 17 08:59:07 stanzetta qobuz-connect[22654]: 20250517 08:59:07.132 [22654.22654] INFO QobuzConnect: [0x13473e0]: Client initialized! May 17 08:59:07 stanzetta qobuz-connect[22654]: 20250517 08:59:07.132 [22654.22654] INFO SampleApp: Starting Avahi advertising, name: Stanzetta, service name: _qobuz-connect._tcp May 17 08:59:07 stanzetta volumio[886]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 17 08:59:07 stanzetta volumio[886]: info: QobuzConnect: QOBUZ Connect daemon connected May 17 08:59:07 stanzetta sudo[22672]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 17 08:59:07 stanzetta sudo[22672]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:07 stanzetta qobuz-connect[22654]: 20250517 08:59:07.167 [22654.22654] INFO LocalConfigManager: [0x13462f0]: Starting Local Configuration server May 17 08:59:07 stanzetta qobuz-connect[22654]: 20250517 08:59:07.167 [22654.22654] INFO SampleApp: Starting Local configuration server May 17 08:59:07 stanzetta qobuz-connect[22654]: 20250517 08:59:07.168 [22654.22654] INFO SampleApp: Connected to UNIX socket client 0x133bf60 May 17 08:59:07 stanzetta systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 17 08:59:07 stanzetta systemd[1]: shairport-sync.service: Succeeded. May 17 08:59:07 stanzetta systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 17 08:59:07 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 08:59:07 stanzetta volumio[886]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 08:59:07 stanzetta qobuz-connect[22654]: 20250517 08:59:07.274 [22654.22654] INFO SampleApp: Playback volume changed: 75 May 17 08:59:07 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:07 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:07 stanzetta systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 17 08:59:07 stanzetta sudo[22672]: pam_unix(sudo:session): session closed for user root May 17 08:59:07 stanzetta volumio[886]: info: Shairport-Sync Started May 17 08:59:07 stanzetta go-librespot[22664]: time="2025-05-17T08:59:07+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 17 08:59:07 stanzetta go-librespot[22664]: time="2025-05-17T08:59:07+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 17 08:59:07 stanzetta go-librespot[22664]: time="2025-05-17T08:59:07+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 17 08:59:07 stanzetta go-librespot[22664]: time="2025-05-17T08:59:07+02:00" level=info msg="zeroconf server listening on port 35363" May 17 08:59:07 stanzetta volumio[886]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists May 17 08:59:07 stanzetta volumio[886]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo May 17 08:59:07 stanzetta volumio[886]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists May 17 08:59:07 stanzetta go-librespot[22664]: time="2025-05-17T08:59:07+02:00" level=debug msg="obtained new client token: AADVKG+rvxkrfOOoCoPeI4SoGypaFLfvq+HmyMXRV4lNXAg/0pr9h9Y2ypP/M0vrO54ed7lKVQf42yLFCXvuiSYaN9LacuiZ8dDgnj6NaYPCxWAvJ7OQvmtkCtcYuFiWaPeYJGYUjZxYdurRt6xjTkf+Q8wF3WIQyGez6H95M63g2nCVMJ3nKVyBOhPN5eF5x6IBc/ni+XFvAcc3X2U4mn7S67rxbhqui2OB6CuX2CAQAnlox79btQFGHodJ" May 17 08:59:07 stanzetta volumio[886]: info: camilladsp service started and running in background, instance 5 May 17 08:59:07 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 08:59:07 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:59:07 stanzetta volumio[886]: cannot open device 'volumioHw': Device or resource busy May 17 08:59:07 stanzetta volumio[886]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json May 17 08:59:07 stanzetta volumio[886]: xcb_connection_has_error() returned true May 17 08:59:07 stanzetta volumio[886]: cannot open device 'volumioHw': Device or resource busy May 17 08:59:07 stanzetta go-librespot[22664]: time="2025-05-17T08:59:07+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 17 08:59:07 stanzetta volumio[886]: info: FusionDsp loaded May 17 08:59:07 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 17 08:59:07 stanzetta volumio[886]: info: FusionDsp - Reporting Fusion DSP Enabled May 17 08:59:07 stanzetta volumio[886]: info: Adding Signal Path Element [object Object] May 17 08:59:07 stanzetta volumio[886]: info: Updating fusiondspeq DSP Signal Path Element May 17 08:59:07 stanzetta volumio[886]: info: FusionDsp - ---- installed callbackRead May 17 08:59:07 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 17 08:59:07 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate from file: 44100 May 17 08:59:07 stanzetta volumio[886]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 17 08:59:07 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 17 08:59:07 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate from file: 44100 May 17 08:59:07 stanzetta volumio[886]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 17 08:59:07 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 17 08:59:07 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate from file: 44100 May 17 08:59:07 stanzetta volumio[886]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 17 08:59:07 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 17 08:59:07 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate from file: 44100 May 17 08:59:07 stanzetta volumio[886]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 17 08:59:07 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 17 08:59:07 stanzetta volumio[886]: info: FusionDsp - ---- read samplerate from file: 44100 May 17 08:59:07 stanzetta volumio[886]: info: camilladsp stopping service pid 22714... May 17 08:59:07 stanzetta go-librespot[22664]: time="2025-05-17T08:59:07+02:00" level=debug msg="completed keyexchange" May 17 08:59:07 stanzetta go-librespot[22664]: time="2025-05-17T08:59:07+02:00" level=debug msg="completed challenge" May 17 08:59:07 stanzetta sudo[22724]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service May 17 08:59:07 stanzetta sudo[22724]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:07 stanzetta volumio[886]: info: camilladsp service terminated, instance 5 May 17 08:59:07 stanzetta volumio[886]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 17 08:59:07 stanzetta volumio[886]: info: camilladsp service started and running in background, instance 5 May 17 08:59:07 stanzetta sudo[22724]: pam_unix(sudo:session): session closed for user root May 17 08:59:07 stanzetta volumio[886]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 17 08:59:07 stanzetta go-librespot[22664]: time="2025-05-17T08:59:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 17 08:59:07 stanzetta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 08:59:07 stanzetta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 08:59:08 stanzetta volumio[886]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 17 May 17 08:59:08 stanzetta volumio[886]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 17 08:59:08 stanzetta volumio[886]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 17 08:59:08 stanzetta volumio[886]: info: TidalConnect service stoped! May 17 08:59:08 stanzetta mpd[22627]: May 17 08:59 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 17 08:59:08 stanzetta volumio[886]: info: TidalConnect service stoped! May 17 08:59:08 stanzetta volumio[886]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 17 08:59:08 stanzetta volumio[886]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 17 08:59:09 stanzetta sudo[22862]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 17 08:59:09 stanzetta sudo[22862]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:09 stanzetta volumio[886]: info: Initializing connection to go-librespot Websocket May 17 08:59:09 stanzetta volumio[886]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 08:59:09 stanzetta systemd[1]: Started Volumio Tidal Connect Service. May 17 08:59:09 stanzetta sudo[22862]: pam_unix(sudo:session): session closed for user root May 17 08:59:09 stanzetta systemd[1]: Started Music Player Daemon. May 17 08:59:09 stanzetta sudo[22558]: pam_unix(sudo:session): session closed for user root May 17 08:59:09 stanzetta sudo[22613]: pam_unix(sudo:session): session closed for user root May 17 08:59:09 stanzetta systemd[1]: Started MPD OLED Plugin. May 17 08:59:09 stanzetta volumio[886]: error: MPD error: The expression evaluated to a falsy value: May 17 08:59:09 stanzetta volumio[886]: assert.ok(self.idling) May 17 08:59:09 stanzetta volumio[886]: error: The expression evaluated to a falsy value: May 17 08:59:09 stanzetta volumio[886]: assert.ok(self.idling) May 17 08:59:09 stanzetta volumio[886]: error: updateQueue error: null May 17 08:59:09 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:09 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:09 stanzetta volumio[886]: info: Executing endpoint tc_getconfig May 17 08:59:09 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 17 08:59:09 stanzetta vtcs[22867]: STARTING TidalConnect services, version: 1.4.0.34 May 17 08:59:09 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:09 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:09 stanzetta vtcs[22867]: STARTED TidalConnect services. May 17 08:59:09 stanzetta volumio[886]: info: TidalConnect service stoped! May 17 08:59:09 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:09 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:09 stanzetta volumio[886]: info: Executing endpoint tc_connect May 17 08:59:09 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect May 17 08:59:09 stanzetta volumio[886]: info: Connecting to TidalConnect May 17 08:59:09 stanzetta volumio[886]: info: TidalConnect service stoped! May 17 08:59:09 stanzetta volumio[886]: info: CoreCommandRouter::servicePushState May 17 08:59:09 stanzetta volumio[886]: info: CoreStateMachine::pushState May 17 08:59:09 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:09 stanzetta volumio[886]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 08:59:09 stanzetta volumio[886]: info: CoreCommandRouter::volumioPushState May 17 08:59:09 stanzetta volumio[886]: info: MRS: Pushing multiroomSync output update for this device May 17 08:59:09 stanzetta volumio[886]: info: MRS: Pushing multiroomSync output May 17 08:59:09 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:09 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:09 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:09 stanzetta volumio[886]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect May 17 08:59:09 stanzetta volumio[886]: info: CoreCommandRouter::servicePushState May 17 08:59:09 stanzetta volumio[886]: info: CoreStateMachine::pushState May 17 08:59:09 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:09 stanzetta volumio[886]: info: CoreCommandRouter::volumioPushState May 17 08:59:09 stanzetta volumio[886]: info: MRS: Pushing multiroomSync output update for this device May 17 08:59:09 stanzetta volumio[886]: info: MRS: Pushing multiroomSync output May 17 08:59:09 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:09 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:09 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:09 stanzetta volumio[886]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect May 17 08:59:10 stanzetta volumio[886]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 17 08:59:10 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:10 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:10 stanzetta volumio[886]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 17 08:59:10 stanzetta volumio[886]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 17 08:59:10 stanzetta sudo[22998]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 17 08:59:10 stanzetta sudo[22998]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:10 stanzetta sudo[22998]: pam_unix(sudo:session): session closed for user root May 17 08:59:10 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:10 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:10 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:10 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:10 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:10 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:10 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:10 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:11 stanzetta systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 08:59:11 stanzetta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1023. May 17 08:59:11 stanzetta systemd[1]: Stopped go-librespot Daemon. May 17 08:59:11 stanzetta systemd[1]: Started go-librespot Daemon. May 17 08:59:11 stanzetta go-librespot[23113]: go-librespot daemon starting... May 17 08:59:11 stanzetta go-librespot[23113]: time="2025-05-17T08:59:11+02:00" level=info msg="running go-librespot 0.2.0" May 17 08:59:11 stanzetta go-librespot[23113]: time="2025-05-17T08:59:11+02:00" level=debug msg="app state loaded" May 17 08:59:11 stanzetta go-librespot[23113]: time="2025-05-17T08:59:11+02:00" level=debug msg="stored credentials not found" May 17 08:59:11 stanzetta go-librespot[23113]: time="2025-05-17T08:59:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 17 08:59:11 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:11 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:11 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:11 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:11 stanzetta go-librespot[23113]: time="2025-05-17T08:59:11+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 17 08:59:11 stanzetta go-librespot[23113]: time="2025-05-17T08:59:11+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 17 08:59:11 stanzetta go-librespot[23113]: time="2025-05-17T08:59:11+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 17 08:59:11 stanzetta go-librespot[23113]: time="2025-05-17T08:59:11+02:00" level=info msg="zeroconf server listening on port 32855" May 17 08:59:11 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:11 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:11 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:11 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:11 stanzetta go-librespot[23113]: time="2025-05-17T08:59:11+02:00" level=debug msg="obtained new client token: AABzgdVZ9KT+LYvpPilYf340CDBBtHf8rzEAh3mIqpmwPWq8spsglESqqJsNldnC0+MbUxu5omOYXgw9MIHOVnTah4/BTDWfmUGPOTO7D7VM2yaPQ1LZUwD103CM5RVpdPfpDYzpLZ64XF3IKhodMOpFe3mkFXc/CXOklekFk1zfoG0YJ6hjyxHfu5x7rj763R/Blj6uxzPv0xB2Oz4vmdsZb89FFMX4JkyK5NjgO0izL2iT6tR74ytUv7Ss" May 17 08:59:11 stanzetta go-librespot[23113]: time="2025-05-17T08:59:11+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 17 08:59:11 stanzetta go-librespot[23113]: time="2025-05-17T08:59:11+02:00" level=debug msg="completed keyexchange" May 17 08:59:11 stanzetta go-librespot[23113]: time="2025-05-17T08:59:11+02:00" level=debug msg="completed challenge" May 17 08:59:11 stanzetta go-librespot[23113]: time="2025-05-17T08:59:11+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 17 08:59:11 stanzetta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 08:59:11 stanzetta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 08:59:12 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:12 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:12 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:12 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:12 stanzetta volumio[886]: info: Initializing connection to go-librespot Websocket May 17 08:59:12 stanzetta volumio[886]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 08:59:12 stanzetta volumio[886]: info: TidalConnect service started! May 17 08:59:12 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:12 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:12 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:12 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:12 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:12 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:13 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:13 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:13 stanzetta volumio[886]: info: TidalConnect service started! May 17 08:59:13 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:13 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:13 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:13 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:13 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:13 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:13 stanzetta volumio[886]: info: CoreCommandRouter::volumioGetState May 17 08:59:13 stanzetta volumio[886]: info: CorePlayQueue::getTrack 1 May 17 08:59:13 stanzetta volumio[886]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 17 08:59:13 stanzetta sudo[23526]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/bin/cp /data/plugins/audio_interface/fusiondsp/c/hw_params_arm /data/plugins/audio_interface/fusiondsp/hw_params May 17 08:59:13 stanzetta sudo[23526]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:13 stanzetta volumio[886]: Error: spawn /data/plugins/audio_interface/fusiondsp/camilladsp EACCES May 17 08:59:13 stanzetta volumio[886]: at Process.ChildProcess._handle.onexit (internal/child_process.js:269:19) May 17 08:59:13 stanzetta volumio[886]: at onErrorNT (internal/child_process.js:465:16) May 17 08:59:13 stanzetta volumio[886]: at processTicksAndRejections (internal/process/task_queues.js:80:21) { May 17 08:59:13 stanzetta volumio[886]: errno: -13, May 17 08:59:13 stanzetta volumio[886]: code: 'EACCES', May 17 08:59:13 stanzetta volumio[886]: syscall: 'spawn /data/plugins/audio_interface/fusiondsp/camilladsp', May 17 08:59:13 stanzetta volumio[886]: path: '/data/plugins/audio_interface/fusiondsp/camilladsp', May 17 08:59:13 stanzetta volumio[886]: spawnargs: [ May 17 08:59:13 stanzetta volumio[886]: '-p', May 17 08:59:13 stanzetta volumio[886]: 9876, May 17 08:59:13 stanzetta volumio[886]: '-o', May 17 08:59:13 stanzetta volumio[886]: '/tmp/camilladsp.log', May 17 08:59:13 stanzetta volumio[886]: '-l', May 17 08:59:13 stanzetta volumio[886]: 'warn', May 17 08:59:13 stanzetta volumio[886]: '/data/configuration/audio_interface/fusiondsp/camilladsp.yml' May 17 08:59:13 stanzetta volumio[886]: ] May 17 08:59:13 stanzetta volumio[886]: } May 17 08:59:13 stanzetta volumio[886]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 17 08:59:13 stanzetta sudo[23526]: pam_unix(sudo:session): session closed for user root May 17 08:59:13 stanzetta sudo[23528]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/bin/chmod +x /data/plugins/audio_interface/fusiondsp/hw_params May 17 08:59:13 stanzetta sudo[23528]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:13 stanzetta sudo[23528]: pam_unix(sudo:session): session closed for user root May 17 08:59:14 stanzetta sudo[23532]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/usr/bin/apt-get -y install drc May 17 08:59:14 stanzetta sudo[23532]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 08:59:14 stanzetta sudo[23557]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-17 08:58 May 17 08:59:14 stanzetta sudo[23557]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:16:30 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3934ee440d5d3f0186049a23752ad680"