-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Tue 2025-03-04 13:07:16 CET. -- Mar 04 13:06:00 volumiopi-rz volumio[1089]: info: Getting Spotify volume Mar 04 13:06:00 volumiopi-rz volumio[1089]: (node:1089) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:00 volumiopi-rz volumio[1089]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 04 13:06:00 volumiopi-rz volumio[1089]: (node:1089) 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: 63) Mar 04 13:06:00 volumiopi-rz volumio[1089]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Mar 04 13:06:00 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioGetState Mar 04 13:06:00 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:00 volumiopi-rz volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Mar 04 13:06:00 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:00 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:00 volumiopi-rz systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 04 13:06:00 volumiopi-rz systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 800. Mar 04 13:06:00 volumiopi-rz systemd[1]: Stopped go-librespot Daemon. Mar 04 13:06:00 volumiopi-rz systemd[1]: Started go-librespot Daemon. Mar 04 13:06:00 volumiopi-rz go-librespot[20066]: Librespot-go daemon starting... Mar 04 13:06:00 volumiopi-rz go-librespot[20066]: time="2025-03-04T13:06:00+01:00" level=info msg="generated new device id: 11389061899d2c898a1e6fc08a51318245a7a4a9" Mar 04 13:06:00 volumiopi-rz go-librespot[20066]: time="2025-03-04T13:06:00+01:00" level=debug msg="stored credentials found for fabian.mundry" Mar 04 13:06:00 volumiopi-rz go-librespot[20066]: time="2025-03-04T13:06:00+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 13:06:00 volumiopi-rz go-librespot[20066]: time="2025-03-04T13:06:00+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 13:06:00 volumiopi-rz go-librespot[20066]: time="2025-03-04T13:06:00+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 13:06:00 volumiopi-rz go-librespot[20066]: time="2025-03-04T13:06:00+01:00" level=debug msg="zeroconf server listening on port 37109" Mar 04 13:06:00 volumiopi-rz go-librespot[20066]: time="2025-03-04T13:06:00+01:00" level=debug msg="obtained new client token: AABpQj6cL4briKgPvB6b8ISoAkkzR5mAnLS5RpXBFe1BPsWCodhiPQh2Y+HLZkQKI+aOewx+HeOPoikEoRPq4Qpn1R82DdGjKH4/x3AiGwLwL3smcSd8/+CgeRJA/D2Qmsq2k4zOqpfrW1Lgx4tnw13trslao/Bi0eiGCsfajPzYBytvmZNKN04LS3CcQUqpII5MgoA5R/Lt7YbOdh4xPUf9a3MaCfD0DF0obro+a4uk8zy5tnoH+toqKWvm6nM=" Mar 04 13:06:00 volumiopi-rz go-librespot[20066]: time="2025-03-04T13:06:00+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 04 13:06:01 volumiopi-rz go-librespot[20066]: time="2025-03-04T13:06:01+01:00" level=debug msg="completed keyexchange" Mar 04 13:06:01 volumiopi-rz go-librespot[20066]: time="2025-03-04T13:06:01+01:00" level=debug msg="completed challenge" Mar 04 13:06:01 volumiopi-rz go-librespot[20066]: time="2025-03-04T13:06:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 04 13:06:01 volumiopi-rz systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 13:06:01 volumiopi-rz systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 13:06:03 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:03 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:04 volumiopi-rz systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 04 13:06:04 volumiopi-rz systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 801. Mar 04 13:06:04 volumiopi-rz systemd[1]: Stopped go-librespot Daemon. Mar 04 13:06:04 volumiopi-rz systemd[1]: Started go-librespot Daemon. Mar 04 13:06:04 volumiopi-rz go-librespot[20076]: Librespot-go daemon starting... Mar 04 13:06:04 volumiopi-rz go-librespot[20076]: time="2025-03-04T13:06:04+01:00" level=info msg="generated new device id: ffdc37311f119919e3aa1d52f72aa679a83dbd5f" Mar 04 13:06:04 volumiopi-rz go-librespot[20076]: time="2025-03-04T13:06:04+01:00" level=debug msg="stored credentials found for fabian.mundry" Mar 04 13:06:04 volumiopi-rz go-librespot[20076]: time="2025-03-04T13:06:04+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 13:06:04 volumiopi-rz go-librespot[20076]: time="2025-03-04T13:06:04+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 13:06:04 volumiopi-rz go-librespot[20076]: time="2025-03-04T13:06:04+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 13:06:04 volumiopi-rz go-librespot[20076]: time="2025-03-04T13:06:04+01:00" level=debug msg="zeroconf server listening on port 33997" Mar 04 13:06:04 volumiopi-rz go-librespot[20076]: time="2025-03-04T13:06:04+01:00" level=debug msg="obtained new client token: AADcYAvbNwsbKd7k+Q/iFVEVY7jzXsuKN4FOL1i0VV4bCzGwrvlkWTMkBQOORMJaHt5Bcar+HZhVLJGVSkvUQ9465xq1MfmJWSDzJzoCoSqGw0AKY6Mh9w54faEAR804U0X1epulx0umfoK+Yo6k+sYZtqYaT7LBSbMQ89Vo5sAayBZ5eWrNquQ8aubI0k0qfulPszGkl7OfN/1d+RjkQJNSa2E7DHoIE9gnHu3gfqGhmXAxA/cEXO6PYpH2Nl0=" Mar 04 13:06:05 volumiopi-rz go-librespot[20076]: time="2025-03-04T13:06:05+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 04 13:06:05 volumiopi-rz go-librespot[20076]: time="2025-03-04T13:06:05+01:00" level=debug msg="completed keyexchange" Mar 04 13:06:05 volumiopi-rz go-librespot[20076]: time="2025-03-04T13:06:05+01:00" level=debug msg="completed challenge" Mar 04 13:06:05 volumiopi-rz go-librespot[20076]: time="2025-03-04T13:06:05+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 04 13:06:05 volumiopi-rz systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 13:06:05 volumiopi-rz systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 13:06:06 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:06 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:08 volumiopi-rz systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 04 13:06:08 volumiopi-rz systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 802. Mar 04 13:06:08 volumiopi-rz systemd[1]: Stopped go-librespot Daemon. Mar 04 13:06:08 volumiopi-rz systemd[1]: Started go-librespot Daemon. Mar 04 13:06:08 volumiopi-rz go-librespot[20098]: Librespot-go daemon starting... Mar 04 13:06:08 volumiopi-rz go-librespot[20098]: time="2025-03-04T13:06:08+01:00" level=info msg="generated new device id: 46403ee0fc4d979fa1bd01a1cb3273d684e62b4b" Mar 04 13:06:08 volumiopi-rz go-librespot[20098]: time="2025-03-04T13:06:08+01:00" level=debug msg="stored credentials found for fabian.mundry" Mar 04 13:06:08 volumiopi-rz go-librespot[20098]: time="2025-03-04T13:06:08+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 13:06:08 volumiopi-rz go-librespot[20098]: time="2025-03-04T13:06:08+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 13:06:08 volumiopi-rz go-librespot[20098]: time="2025-03-04T13:06:08+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 13:06:08 volumiopi-rz go-librespot[20098]: time="2025-03-04T13:06:08+01:00" level=debug msg="zeroconf server listening on port 45117" Mar 04 13:06:08 volumiopi-rz go-librespot[20098]: time="2025-03-04T13:06:08+01:00" level=debug msg="obtained new client token: AAC+jNlkq7FjZ3Tb/z6WBAipIqitbmAFBus0AI4KF5KNe/USPUuAECT2Gx8abAgMEh7cpiCNpm55QK/N+u1x4QF+bKyDd+JPn3aTFqTT6pA+SctWhR1SQHP8dR20C4mcZFskJP39EQVykjGlyfo3o6bGM09MwblHnaWNWKC0msP8JS1HpNG6Z9npnpMPu8vz3NP+aXgSLDEKX6j9L6/XuLwIw1ljRoLk+RTgQmcdRDx4iLUDgmP5vBUKAQ1+QrY=" Mar 04 13:06:08 volumiopi-rz go-librespot[20098]: time="2025-03-04T13:06:08+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 04 13:06:09 volumiopi-rz go-librespot[20098]: time="2025-03-04T13:06:09+01:00" level=debug msg="completed keyexchange" Mar 04 13:06:09 volumiopi-rz go-librespot[20098]: time="2025-03-04T13:06:09+01:00" level=debug msg="completed challenge" Mar 04 13:06:09 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:09 volumiopi-rz go-librespot[20098]: time="2025-03-04T13:06:09+01:00" level=debug msg="new websocket client" Mar 04 13:06:09 volumiopi-rz volumio[1089]: info: Connection to go-librespot Websocket established Mar 04 13:06:09 volumiopi-rz go-librespot[20098]: time="2025-03-04T13:06:09+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 04 13:06:09 volumiopi-rz systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 13:06:09 volumiopi-rz systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 13:06:09 volumiopi-rz volumio[1089]: info: Connection to go-librespot Websocket closed Mar 04 13:06:12 volumiopi-rz volumio[1089]: info: Getting Spotify volume Mar 04 13:06:12 volumiopi-rz volumio[1089]: (node:1089) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:12 volumiopi-rz volumio[1089]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 04 13:06:12 volumiopi-rz volumio[1089]: (node:1089) 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: 64) Mar 04 13:06:12 volumiopi-rz volumio[1089]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Mar 04 13:06:12 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:12 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:12 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioGetState Mar 04 13:06:12 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:12 volumiopi-rz volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Mar 04 13:06:12 volumiopi-rz systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 04 13:06:12 volumiopi-rz systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 803. Mar 04 13:06:12 volumiopi-rz systemd[1]: Stopped go-librespot Daemon. Mar 04 13:06:12 volumiopi-rz systemd[1]: Started go-librespot Daemon. Mar 04 13:06:12 volumiopi-rz go-librespot[20108]: Librespot-go daemon starting... Mar 04 13:06:12 volumiopi-rz go-librespot[20108]: time="2025-03-04T13:06:12+01:00" level=info msg="generated new device id: dced2799a22b5ce67e3cbb3ce3d9143062896fe5" Mar 04 13:06:12 volumiopi-rz go-librespot[20108]: time="2025-03-04T13:06:12+01:00" level=debug msg="stored credentials found for fabian.mundry" Mar 04 13:06:12 volumiopi-rz go-librespot[20108]: time="2025-03-04T13:06:12+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 13:06:12 volumiopi-rz go-librespot[20108]: time="2025-03-04T13:06:12+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 13:06:12 volumiopi-rz go-librespot[20108]: time="2025-03-04T13:06:12+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 13:06:12 volumiopi-rz go-librespot[20108]: time="2025-03-04T13:06:12+01:00" level=debug msg="zeroconf server listening on port 37621" Mar 04 13:06:12 volumiopi-rz go-librespot[20108]: time="2025-03-04T13:06:12+01:00" level=debug msg="obtained new client token: AABW21tWMofj5Arf7J6BbQSvwPemLloxtQ5vfvI8SDBkBWIdXNHzHlr3ns5PIpe6ZEH9Eikqq2pBjshn+uSyJA34BpcvK0JjDcbesEu+9aw97z6i7AN0Wx12d1gbZ0Op9NpKFKQUVXjLeIsXSYDtMOEJ4kgVCr0cuNOevUnEqar+3qm0VVrGkiR6Ypp6i4DFr0wvlPbtdVsfLS0hu2E8qfvnzMeOY6AZI20+3x8jtu/++rn5DFlMifdLP9lW8T8=" Mar 04 13:06:12 volumiopi-rz go-librespot[20108]: time="2025-03-04T13:06:12+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 04 13:06:13 volumiopi-rz go-librespot[20108]: time="2025-03-04T13:06:13+01:00" level=debug msg="completed keyexchange" Mar 04 13:06:13 volumiopi-rz go-librespot[20108]: time="2025-03-04T13:06:13+01:00" level=debug msg="completed challenge" Mar 04 13:06:13 volumiopi-rz go-librespot[20108]: time="2025-03-04T13:06:13+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 04 13:06:13 volumiopi-rz systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 13:06:13 volumiopi-rz systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 13:06:15 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:15 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:16 volumiopi-rz systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 04 13:06:16 volumiopi-rz systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 804. Mar 04 13:06:16 volumiopi-rz systemd[1]: Stopped go-librespot Daemon. Mar 04 13:06:16 volumiopi-rz systemd[1]: Started go-librespot Daemon. Mar 04 13:06:16 volumiopi-rz go-librespot[20131]: Librespot-go daemon starting... Mar 04 13:06:16 volumiopi-rz go-librespot[20131]: time="2025-03-04T13:06:16+01:00" level=info msg="generated new device id: bae38fc2432acb50efeaa46c50d8dd93e675547e" Mar 04 13:06:16 volumiopi-rz go-librespot[20131]: time="2025-03-04T13:06:16+01:00" level=debug msg="stored credentials found for fabian.mundry" Mar 04 13:06:16 volumiopi-rz go-librespot[20131]: time="2025-03-04T13:06:16+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 13:06:16 volumiopi-rz go-librespot[20131]: time="2025-03-04T13:06:16+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 13:06:16 volumiopi-rz go-librespot[20131]: time="2025-03-04T13:06:16+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 13:06:16 volumiopi-rz go-librespot[20131]: time="2025-03-04T13:06:16+01:00" level=debug msg="zeroconf server listening on port 36329" Mar 04 13:06:16 volumiopi-rz go-librespot[20131]: time="2025-03-04T13:06:16+01:00" level=debug msg="obtained new client token: AAAtlxqx8Xhz8sN1BmL2DlHP7GSN+WKW8dSaySX240dwXQrb0AXEltfejXIS0B07PJRL8858qew+ZN8akfAT2UAYdTCUXvI/b9mBXgNQSsyvzRQYhwQNbcDfvzFltjgG6j71b+u1jiS/pfhA0tR3yAVhOX7UYV5qIbQo35uyJ3nk55Ok4YNpS+Xs3a4Tu0/3hu/GWMC8Q/joh1P/53TLBK9i0NzsTxLC06y3hsn438mztANtGoVTVp7QpTO3N2U=" Mar 04 13:06:16 volumiopi-rz go-librespot[20131]: time="2025-03-04T13:06:16+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 04 13:06:17 volumiopi-rz go-librespot[20131]: time="2025-03-04T13:06:17+01:00" level=debug msg="completed keyexchange" Mar 04 13:06:17 volumiopi-rz go-librespot[20131]: time="2025-03-04T13:06:17+01:00" level=debug msg="completed challenge" Mar 04 13:06:17 volumiopi-rz go-librespot[20131]: time="2025-03-04T13:06:17+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 04 13:06:17 volumiopi-rz systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 13:06:17 volumiopi-rz systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 13:06:18 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:18 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:20 volumiopi-rz systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 04 13:06:20 volumiopi-rz systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 805. Mar 04 13:06:20 volumiopi-rz systemd[1]: Stopped go-librespot Daemon. Mar 04 13:06:20 volumiopi-rz systemd[1]: Started go-librespot Daemon. Mar 04 13:06:20 volumiopi-rz go-librespot[20142]: Librespot-go daemon starting... Mar 04 13:06:20 volumiopi-rz go-librespot[20142]: time="2025-03-04T13:06:20+01:00" level=info msg="generated new device id: 9c39e7512f83aee57fe7950b36bb8bb77e9da2d8" Mar 04 13:06:20 volumiopi-rz go-librespot[20142]: time="2025-03-04T13:06:20+01:00" level=debug msg="stored credentials found for fabian.mundry" Mar 04 13:06:20 volumiopi-rz go-librespot[20142]: time="2025-03-04T13:06:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 13:06:20 volumiopi-rz go-librespot[20142]: time="2025-03-04T13:06:20+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 13:06:20 volumiopi-rz go-librespot[20142]: time="2025-03-04T13:06:20+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 13:06:20 volumiopi-rz go-librespot[20142]: time="2025-03-04T13:06:20+01:00" level=debug msg="zeroconf server listening on port 36873" Mar 04 13:06:20 volumiopi-rz go-librespot[20142]: time="2025-03-04T13:06:20+01:00" level=debug msg="obtained new client token: AACGqLQZCgBqNx+et/98wUWBTRkatDBnazuDQyurD+GsQTCxB9KuneeuLniYEKJNlg+N0OYtKQ2lL/KJdrrRAe5njTp5rKeFmpOhRYkOjLZQ8534kv0gZ9l44LceOZytAzFMYzpb3TNN0oJsaX1Jjn0AuaiCbFUMZwVqkUkLJrMoCTSJp8fs6t4sAzUCBjGd272c7zJ+MvCQYFAzZ4BOrOoXyjs/dWK3ktExIzq0PDaWc8IlX/Dh/5eRO2nwNW8=" Mar 04 13:06:20 volumiopi-rz go-librespot[20142]: time="2025-03-04T13:06:20+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 04 13:06:20 volumiopi-rz go-librespot[20142]: time="2025-03-04T13:06:20+01:00" level=debug msg="completed keyexchange" Mar 04 13:06:21 volumiopi-rz go-librespot[20142]: time="2025-03-04T13:06:21+01:00" level=debug msg="completed challenge" Mar 04 13:06:21 volumiopi-rz go-librespot[20142]: time="2025-03-04T13:06:21+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 04 13:06:21 volumiopi-rz systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 13:06:21 volumiopi-rz systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 13:06:21 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:21 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:24 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:24 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:24 volumiopi-rz systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 04 13:06:24 volumiopi-rz systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 806. Mar 04 13:06:24 volumiopi-rz systemd[1]: Stopped go-librespot Daemon. Mar 04 13:06:24 volumiopi-rz systemd[1]: Started go-librespot Daemon. Mar 04 13:06:24 volumiopi-rz go-librespot[20153]: Librespot-go daemon starting... Mar 04 13:06:24 volumiopi-rz go-librespot[20153]: time="2025-03-04T13:06:24+01:00" level=info msg="generated new device id: 8d266c4645b7689925862f54f3d72aa61b3e951d" Mar 04 13:06:24 volumiopi-rz go-librespot[20153]: time="2025-03-04T13:06:24+01:00" level=debug msg="stored credentials found for fabian.mundry" Mar 04 13:06:24 volumiopi-rz go-librespot[20153]: time="2025-03-04T13:06:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 13:06:24 volumiopi-rz go-librespot[20153]: time="2025-03-04T13:06:24+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 13:06:24 volumiopi-rz go-librespot[20153]: time="2025-03-04T13:06:24+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 13:06:24 volumiopi-rz go-librespot[20153]: time="2025-03-04T13:06:24+01:00" level=debug msg="zeroconf server listening on port 35039" Mar 04 13:06:25 volumiopi-rz go-librespot[20153]: time="2025-03-04T13:06:25+01:00" level=debug msg="obtained new client token: AACJe0AWxLaYSQfbQuzRMHFfLLk5WmmINrON4oGpTIcdARpV+0v9cusLrGv5V45LoNVzU2UfNY40uxatORwRpKY6XQqi7oVgYUwH/a561hF3dIF1NxFsqAJTPYgKhh7fwJ9DxeYKuQA/rRFCr/ehzlD8K5VBWO99GFTS+zoAy0m85sW0mYmXEYfFETV91P8DXoijWSyls+jQlSswOkZEiCPSvcZbPFolCZ2NLWzFuS440i3eI+jW7cs0QqT4" Mar 04 13:06:25 volumiopi-rz go-librespot[20153]: time="2025-03-04T13:06:25+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 04 13:06:25 volumiopi-rz go-librespot[20153]: time="2025-03-04T13:06:25+01:00" level=debug msg="completed keyexchange" Mar 04 13:06:25 volumiopi-rz go-librespot[20153]: time="2025-03-04T13:06:25+01:00" level=debug msg="completed challenge" Mar 04 13:06:25 volumiopi-rz go-librespot[20153]: time="2025-03-04T13:06:25+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 04 13:06:25 volumiopi-rz systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 13:06:25 volumiopi-rz systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPlay Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreStateMachine::play index undefined Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreStateMachine::startPlaybackTimer Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioGetVisibleSources Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: [ytmusic-play] clearAddPlayTrack: ytmusic/song@explodeTrackData:o=%7B%22type%22%3A%22song%22%2C%22title%22%3A%22Relaxing%20Music%22%2C%22artist%22%3A%22Soothing%20Sounds%22%2C%22album%22%3A%22Relaxing%20Music%22%2C%22albumart%22%3A%22https%3A%2F%2Flh3.googleusercontent.com%2FoK0i2XW3fiMwep3FvawAZOhIwqlQvZ3-JDZqQ85NosyDEetyZiM-xSn9AgqU1gbkRUxf1mOKpQbK625avw%3Dw701-h701-l90-rj%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%2C%22autoplayContext%22%3A%7B%22fetchEndpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%7D%7D Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPlay Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreStateMachine::play index undefined Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreStateMachine::startPlaybackTimer Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioGetVisibleSources Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: [ytmusic-play] clearAddPlayTrack: ytmusic/song@explodeTrackData:o=%7B%22type%22%3A%22song%22%2C%22title%22%3A%22Relaxing%20Music%22%2C%22artist%22%3A%22Soothing%20Sounds%22%2C%22album%22%3A%22Relaxing%20Music%22%2C%22albumart%22%3A%22https%3A%2F%2Flh3.googleusercontent.com%2FoK0i2XW3fiMwep3FvawAZOhIwqlQvZ3-JDZqQ85NosyDEetyZiM-xSn9AgqU1gbkRUxf1mOKpQbK625avw%3Dw701-h701-l90-rj%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%2C%22autoplayContext%22%3A%7B%22fetchEndpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%7D%7D Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPlay Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreStateMachine::play index undefined Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreStateMachine::startPlaybackTimer Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioGetVisibleSources Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: [ytmusic-play] clearAddPlayTrack: ytmusic/song@explodeTrackData:o=%7B%22type%22%3A%22song%22%2C%22title%22%3A%22Relaxing%20Music%22%2C%22artist%22%3A%22Soothing%20Sounds%22%2C%22album%22%3A%22Relaxing%20Music%22%2C%22albumart%22%3A%22https%3A%2F%2Flh3.googleusercontent.com%2FoK0i2XW3fiMwep3FvawAZOhIwqlQvZ3-JDZqQ85NosyDEetyZiM-xSn9AgqU1gbkRUxf1mOKpQbK625avw%3Dw701-h701-l90-rj%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%2C%22autoplayContext%22%3A%7B%22fetchEndpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%7D%7D Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPlay Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreStateMachine::play index undefined Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreStateMachine::startPlaybackTimer Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioGetVisibleSources Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 04 13:06:26 volumiopi-rz volumio[1089]: info: [ytmusic-play] clearAddPlayTrack: ytmusic/song@explodeTrackData:o=%7B%22type%22%3A%22song%22%2C%22title%22%3A%22Relaxing%20Music%22%2C%22artist%22%3A%22Soothing%20Sounds%22%2C%22album%22%3A%22Relaxing%20Music%22%2C%22albumart%22%3A%22https%3A%2F%2Flh3.googleusercontent.com%2FoK0i2XW3fiMwep3FvawAZOhIwqlQvZ3-JDZqQ85NosyDEetyZiM-xSn9AgqU1gbkRUxf1mOKpQbK625avw%3Dw701-h701-l90-rj%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%2C%22autoplayContext%22%3A%7B%22fetchEndpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%7D%7D Mar 04 13:06:27 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPlay Mar 04 13:06:27 volumiopi-rz volumio[1089]: info: CoreStateMachine::play index undefined Mar 04 13:06:27 volumiopi-rz volumio[1089]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 13:06:27 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:27 volumiopi-rz volumio[1089]: info: CoreStateMachine::startPlaybackTimer Mar 04 13:06:27 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:27 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioGetVisibleSources Mar 04 13:06:27 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 13:06:27 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 04 13:06:27 volumiopi-rz volumio[1089]: info: [ytmusic-play] clearAddPlayTrack: ytmusic/song@explodeTrackData:o=%7B%22type%22%3A%22song%22%2C%22title%22%3A%22Relaxing%20Music%22%2C%22artist%22%3A%22Soothing%20Sounds%22%2C%22album%22%3A%22Relaxing%20Music%22%2C%22albumart%22%3A%22https%3A%2F%2Flh3.googleusercontent.com%2FoK0i2XW3fiMwep3FvawAZOhIwqlQvZ3-JDZqQ85NosyDEetyZiM-xSn9AgqU1gbkRUxf1mOKpQbK625avw%3Dw701-h701-l90-rj%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%2C%22autoplayContext%22%3A%7B%22fetchEndpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%7D%7D Mar 04 13:06:27 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:27 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:28 volumiopi-rz systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 04 13:06:28 volumiopi-rz systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 807. Mar 04 13:06:28 volumiopi-rz systemd[1]: Stopped go-librespot Daemon. Mar 04 13:06:28 volumiopi-rz systemd[1]: Started go-librespot Daemon. Mar 04 13:06:28 volumiopi-rz go-librespot[20176]: Librespot-go daemon starting... Mar 04 13:06:28 volumiopi-rz go-librespot[20176]: time="2025-03-04T13:06:28+01:00" level=info msg="generated new device id: 7fb6cf67beb7ff81e0aa09f790a11d9a95c3b2aa" Mar 04 13:06:28 volumiopi-rz go-librespot[20176]: time="2025-03-04T13:06:28+01:00" level=debug msg="stored credentials found for fabian.mundry" Mar 04 13:06:28 volumiopi-rz go-librespot[20176]: time="2025-03-04T13:06:28+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 13:06:28 volumiopi-rz go-librespot[20176]: time="2025-03-04T13:06:28+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 13:06:28 volumiopi-rz go-librespot[20176]: time="2025-03-04T13:06:28+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 13:06:28 volumiopi-rz go-librespot[20176]: time="2025-03-04T13:06:28+01:00" level=debug msg="zeroconf server listening on port 37235" Mar 04 13:06:28 volumiopi-rz go-librespot[20176]: time="2025-03-04T13:06:28+01:00" level=debug msg="obtained new client token: AAC7v2//xdNzybxkuc/BfKcK2LnPIeUPWVteMa4H4qax6Nl0Sj/X+mbJl9UE/WkcCn7GMRz9/UaICZmmeM9blqHviLmoOjCWijtK4Hp3pb8B6Jt+eXHcG2/lUaijXdvACfNEKZoLEQOoee5edMe+RQNSGNrziZ5D9Eq0hji8WYQ6sTBthArFNDMwm09gZQM6e5S558tlljkSv7f/qtE07sSIsSmoppKazRCNPlbVrCff8sSM+56qwo/pCQBt81o=" Mar 04 13:06:28 volumiopi-rz go-librespot[20176]: time="2025-03-04T13:06:28+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070 (error: dial tcp 34.158.1.133:4070: connect: connection refused), retrying with a different AP" Mar 04 13:06:28 volumiopi-rz go-librespot[20176]: time="2025-03-04T13:06:28+01:00" level=info msg="connected to ap-gew4.spotify.com:443" Mar 04 13:06:29 volumiopi-rz go-librespot[20176]: time="2025-03-04T13:06:29+01:00" level=debug msg="completed keyexchange" Mar 04 13:06:29 volumiopi-rz go-librespot[20176]: time="2025-03-04T13:06:29+01:00" level=debug msg="completed challenge" Mar 04 13:06:29 volumiopi-rz go-librespot[20176]: time="2025-03-04T13:06:29+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 04 13:06:29 volumiopi-rz systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 13:06:29 volumiopi-rz systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 13:06:30 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:30 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:32 volumiopi-rz systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 04 13:06:32 volumiopi-rz systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 808. Mar 04 13:06:32 volumiopi-rz systemd[1]: Stopped go-librespot Daemon. Mar 04 13:06:32 volumiopi-rz systemd[1]: Started go-librespot Daemon. Mar 04 13:06:32 volumiopi-rz go-librespot[20187]: Librespot-go daemon starting... Mar 04 13:06:32 volumiopi-rz go-librespot[20187]: time="2025-03-04T13:06:32+01:00" level=info msg="generated new device id: 5bf663cac248510999762814ab0aa459ef94bca5" Mar 04 13:06:32 volumiopi-rz go-librespot[20187]: time="2025-03-04T13:06:32+01:00" level=debug msg="stored credentials found for fabian.mundry" Mar 04 13:06:32 volumiopi-rz go-librespot[20187]: time="2025-03-04T13:06:32+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 13:06:32 volumiopi-rz go-librespot[20187]: time="2025-03-04T13:06:32+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 13:06:32 volumiopi-rz go-librespot[20187]: time="2025-03-04T13:06:32+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 13:06:32 volumiopi-rz go-librespot[20187]: time="2025-03-04T13:06:32+01:00" level=debug msg="zeroconf server listening on port 37051" Mar 04 13:06:32 volumiopi-rz go-librespot[20187]: time="2025-03-04T13:06:32+01:00" level=debug msg="obtained new client token: AADwu6QAIih2PpWs+aPejtkq2mafBZwwMjXRfiQumPCjMlNNiu44mIiEgXc7LnIpxmkAriDWeQVpJf+cu1gdAfJOK45VWTx+aCyCLXAscCprgrCYILkJLwCR2eEyWBWHvg/w6ffLVI6VgxBeCl0Gra7G1b2bDFtLbmIjAlaV8k3t778tru1x6qIr/2Crxd4/z3w/3BMSpxkL3ru+WO+pORANXrDQpodQGmpeURDZU6lKTRe0xNW+h9wqB4p5Qo8=" Mar 04 13:06:32 volumiopi-rz go-librespot[20187]: time="2025-03-04T13:06:32+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 04 13:06:33 volumiopi-rz go-librespot[20187]: time="2025-03-04T13:06:33+01:00" level=debug msg="completed keyexchange" Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: Preparing to save Alsa Options, stopping services first Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioGetState Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPause Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreStateMachine::pause Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: Saving Audio Output to: {"output_device":{"value":"1","label":"Headphones"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: Found match in Cards Database: setting mixer PCM for card Headphones Mar 04 13:06:33 volumiopi-rz vtcs[2159]: [2025-03-04 13:06:33.411] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE Mar 04 13:06:33 volumiopi-rz vtcs[2159]: [2025-03-04 13:06:33.412] [tisoc] [error] [SpkconServer.cpp:381] recv error. client fd=7 errorno=104 error=Connection reset by peer Mar 04 13:06:33 volumiopi-rz vtcs[2159]: [2025-03-04 13:06:33.412] [tisoc] [error] [SpkconServer.cpp:376] recv error. socket disconnected Mar 04 13:06:33 volumiopi-rz sudo[20200]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 13:06:33 volumiopi-rz sudo[20200]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:33 volumiopi-rz systemd[1]: Stopping Volumio Tidal Connect Service... Mar 04 13:06:33 volumiopi-rz systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Mar 04 13:06:33 volumiopi-rz systemd[1]: vtcs.service: Succeeded. Mar 04 13:06:33 volumiopi-rz systemd[1]: Stopped Volumio Tidal Connect Service. Mar 04 13:06:33 volumiopi-rz sudo[20200]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioUpdateVolumeSettings Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: Updating Volume Controller Parameters: Device: 1 Name: Headphones Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: Disabling external Volume Control Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: Preparing to generate the ALSA configuration file Mar 04 13:06:33 volumiopi-rz go-librespot[20187]: time="2025-03-04T13:06:33+01:00" level=debug msg="completed challenge" Mar 04 13:06:33 volumiopi-rz go-librespot[20187]: time="2025-03-04T13:06:33+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 04 13:06:33 volumiopi-rz systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 13:06:33 volumiopi-rz systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 13:06:33 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: Reading ALSA contributions from plugins. Mar 04 13:06:33 volumiopi-rz sudo[20207]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 13:06:33 volumiopi-rz sudo[20207]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:33 volumiopi-rz sudo[20207]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: VolumeController:: Volume=86 Mute =false Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreStateMachine::pushState Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPushState Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output update for this device Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 04 13:06:33 volumiopi-rz volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 04 13:06:33 volumiopi-rz volumio[1089]: SPOTIFY: SPOTIFY VOLUME 51 Mar 04 13:06:33 volumiopi-rz volumio[1089]: SPOTIFY: VOLUMIO VOLUME 86 Mar 04 13:06:33 volumiopi-rz volumio[1089]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: Setting Spotify Volume from Volumio: 86 Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: Asound.conf file written Mar 04 13:06:33 volumiopi-rz sudo[20216]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Mar 04 13:06:33 volumiopi-rz sudo[20216]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:33 volumiopi-rz sudo[20216]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:33 volumiopi-rz volumio[1089]: info: Output device has changed, restarting MPD Mar 04 13:06:33 volumiopi-rz sudo[20222]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 13:06:33 volumiopi-rz sudo[20222]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:34 volumiopi-rz sudo[20222]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: Output device has changed, restarting Shairport Sync Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 13:06:34 volumiopi-rz sudo[20225]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 13:06:34 volumiopi-rz sudo[20225]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:34 volumiopi-rz systemd[1]: musicservicesshield.service: Succeeded. Mar 04 13:06:34 volumiopi-rz systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Mar 04 13:06:34 volumiopi-rz systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Mar 04 13:06:34 volumiopi-rz systemd[1]: Stopping Music Player Daemon... Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 04 13:06:34 volumiopi-rz systemd[1]: mpd.service: Succeeded. Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:34 volumiopi-rz systemd[1]: Stopped Music Player Daemon. Mar 04 13:06:34 volumiopi-rz systemd[1]: Starting Music Player Daemon... Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: Output device has changed, restarting MPD Mar 04 13:06:34 volumiopi-rz sudo[20235]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 13:06:34 volumiopi-rz sudo[20235]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: Output device has changed, restarting Shairport Sync Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 13:06:34 volumiopi-rz sudo[20235]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:34 volumiopi-rz sudo[20238]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 13:06:34 volumiopi-rz sudo[20238]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:34 volumiopi-rz sudo[20238]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:34 volumiopi-rz sudo[20240]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 13:06:34 volumiopi-rz sudo[20240]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:34 volumiopi-rz sudo[20230]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 13:06:34 volumiopi-rz sudo[20230]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:34 volumiopi-rz sudo[20230]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:34 volumiopi-rz systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Mar 04 13:06:34 volumiopi-rz systemd[1]: mpd.service: Succeeded. Mar 04 13:06:34 volumiopi-rz systemd[1]: Stopped Music Player Daemon. Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:34 volumiopi-rz systemd[1]: Starting Music Player Daemon... Mar 04 13:06:34 volumiopi-rz sudo[20251]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 13:06:34 volumiopi-rz sudo[20251]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:34 volumiopi-rz sudo[20247]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 13:06:34 volumiopi-rz sudo[20247]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:34 volumiopi-rz sudo[20251]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:34 volumiopi-rz sudo[20247]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:34 volumiopi-rz sudo[20254]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 13:06:34 volumiopi-rz sudo[20254]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:34 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:34 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:34 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:34 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:34 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:34 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:34 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: MPD Permissions set Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:34 volumiopi-rz sudo[20260]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 13:06:34 volumiopi-rz sudo[20260]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: Starting Shairport Sync Mar 04 13:06:34 volumiopi-rz sudo[20260]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: Starting Shairport Sync Mar 04 13:06:34 volumiopi-rz sudo[20254]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:34 volumiopi-rz sudo[20272]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 13:06:34 volumiopi-rz sudo[20272]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:34 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:34 volumiopi-rz sudo[20276]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 13:06:34 volumiopi-rz sudo[20276]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: Preparing to generate the ALSA configuration file Mar 04 13:06:34 volumiopi-rz systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: Reading ALSA contributions from plugins. Mar 04 13:06:34 volumiopi-rz systemd[1]: shairport-sync.service: Succeeded. Mar 04 13:06:34 volumiopi-rz systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 04 13:06:34 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:34 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:34 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: Asound.conf file written Mar 04 13:06:34 volumiopi-rz sudo[20280]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Mar 04 13:06:34 volumiopi-rz sudo[20280]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:34 volumiopi-rz systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 04 13:06:34 volumiopi-rz sudo[20280]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:34 volumiopi-rz sudo[20272]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:34 volumiopi-rz sudo[20276]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: Output device has changed, restarting MPD Mar 04 13:06:34 volumiopi-rz sudo[20288]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 13:06:34 volumiopi-rz sudo[20288]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:34 volumiopi-rz sudo[20288]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: Output device has changed, restarting Shairport Sync Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 13:06:34 volumiopi-rz sudo[20291]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 13:06:34 volumiopi-rz sudo[20291]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:34 volumiopi-rz systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Mar 04 13:06:34 volumiopi-rz systemd[1]: mpd.service: Succeeded. Mar 04 13:06:34 volumiopi-rz systemd[1]: Stopped Music Player Daemon. Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:34 volumiopi-rz systemd[1]: Starting Music Player Daemon... Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: Preparing to generate the ALSA configuration file Mar 04 13:06:34 volumiopi-rz sudo[20300]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 13:06:34 volumiopi-rz sudo[20300]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: FusionDsp - eq1: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:34 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:34 volumiopi-rz volumio[1089]: freq: 25 Mar 04 13:06:34 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:34 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:34 volumiopi-rz volumio[1089]: eq2: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:34 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:34 volumiopi-rz volumio[1089]: freq: 40 Mar 04 13:06:34 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:34 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:34 volumiopi-rz volumio[1089]: eq3: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:34 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:34 volumiopi-rz volumio[1089]: freq: 63 Mar 04 13:06:34 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:34 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:34 volumiopi-rz volumio[1089]: eq4: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:34 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:34 volumiopi-rz volumio[1089]: freq: 100 Mar 04 13:06:34 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:34 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:34 volumiopi-rz volumio[1089]: eq5: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:34 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:34 volumiopi-rz volumio[1089]: freq: 160 Mar 04 13:06:34 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:34 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:34 volumiopi-rz volumio[1089]: eq6: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:34 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:34 volumiopi-rz volumio[1089]: freq: 250 Mar 04 13:06:34 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:34 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:34 volumiopi-rz volumio[1089]: eq7: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:34 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:34 volumiopi-rz volumio[1089]: freq: 400 Mar 04 13:06:34 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:34 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:34 volumiopi-rz volumio[1089]: eq8: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:34 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:34 volumiopi-rz volumio[1089]: freq: 630 Mar 04 13:06:34 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:34 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:34 volumiopi-rz volumio[1089]: eq9: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:34 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:34 volumiopi-rz volumio[1089]: freq: 1000 Mar 04 13:06:34 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:34 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:34 volumiopi-rz volumio[1089]: eq10: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:34 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:34 volumiopi-rz volumio[1089]: freq: 1600 Mar 04 13:06:34 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:34 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:34 volumiopi-rz volumio[1089]: eq11: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:34 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:34 volumiopi-rz volumio[1089]: freq: 2500 Mar 04 13:06:34 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:34 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:34 volumiopi-rz volumio[1089]: eq12: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:34 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:34 volumiopi-rz volumio[1089]: freq: 4000 Mar 04 13:06:34 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:34 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:34 volumiopi-rz volumio[1089]: eq13: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:34 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:34 volumiopi-rz volumio[1089]: freq: 6300 Mar 04 13:06:34 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:34 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:34 volumiopi-rz volumio[1089]: eq14: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:34 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:34 volumiopi-rz volumio[1089]: freq: 10000 Mar 04 13:06:34 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:34 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:34 volumiopi-rz volumio[1089]: eq15: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:34 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:34 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:34 volumiopi-rz volumio[1089]: freq: 16000 Mar 04 13:06:34 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:34 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:34 volumiopi-rz sudo[20300]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Mar 04 13:06:34 volumiopi-rz sudo[20296]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Mar 04 13:06:34 volumiopi-rz volumio[1089]: info: Reading ALSA contributions from plugins. Mar 04 13:06:34 volumiopi-rz sudo[20296]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:34 volumiopi-rz sudo[20303]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 13:06:34 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:34 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:34 volumiopi-rz sudo[20296]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:34 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:34 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:34 volumiopi-rz sudo[20303]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:35 volumiopi-rz sudo[20313]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: MPD Permissions set Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: Shairport-Sync Started Mar 04 13:06:35 volumiopi-rz volumio[1089]: error: FusionDsp - WebSocket error: [object Object] Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: Starting Shairport Sync Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: Asound.conf file unchanged, so no further update is needed Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: Output device has changed, restarting MPD Mar 04 13:06:35 volumiopi-rz sudo[20313]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:35 volumiopi-rz sudo[20303]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:35 volumiopi-rz sudo[20316]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 13:06:35 volumiopi-rz sudo[20316]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:35 volumiopi-rz systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 04 13:06:35 volumiopi-rz sudo[20316]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:35 volumiopi-rz systemd[1]: shairport-sync.service: Succeeded. Mar 04 13:06:35 volumiopi-rz systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 04 13:06:35 volumiopi-rz systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 04 13:06:35 volumiopi-rz sudo[20313]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:35 volumiopi-rz sudo[20321]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 13:06:35 volumiopi-rz sudo[20321]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: Output device has changed, restarting Shairport Sync Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 13:06:35 volumiopi-rz systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Mar 04 13:06:35 volumiopi-rz systemd[1]: mpd.service: Succeeded. Mar 04 13:06:35 volumiopi-rz systemd[1]: Stopped Music Player Daemon. Mar 04 13:06:35 volumiopi-rz systemd[1]: Starting Music Player Daemon... Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:35 volumiopi-rz sudo[20327]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 13:06:35 volumiopi-rz sudo[20327]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:35 volumiopi-rz sudo[20327]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:35 volumiopi-rz sudo[20332]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 13:06:35 volumiopi-rz sudo[20332]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:35 volumiopi-rz volumio[1089]: SPOTIFY: SETTING SPOTIFY VOLUME 86 Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: Sending Spotify command with payload to local API: /player/volume Mar 04 13:06:35 volumiopi-rz sudo[20337]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 13:06:35 volumiopi-rz sudo[20332]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:35 volumiopi-rz sudo[20337]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:35 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:35 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:35 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:35 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:35 volumiopi-rz sudo[20337]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:35 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:35 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:35 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:35 volumiopi-rz volumio[1089]: error: Failed to send command to Spotify local API: /player/volume: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: MPD Permissions set Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: Shairport-Sync Started Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: Starting Shairport Sync Mar 04 13:06:35 volumiopi-rz sudo[20346]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 13:06:35 volumiopi-rz sudo[20346]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:35 volumiopi-rz systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 04 13:06:35 volumiopi-rz systemd[1]: shairport-sync.service: Succeeded. Mar 04 13:06:35 volumiopi-rz systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 04 13:06:35 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:35 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:35 volumiopi-rz systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 04 13:06:35 volumiopi-rz sudo[20346]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:35 volumiopi-rz volumio[1089]: info: Shairport-Sync Started Mar 04 13:06:36 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPlay Mar 04 13:06:36 volumiopi-rz volumio[1089]: info: CoreStateMachine::play index undefined Mar 04 13:06:36 volumiopi-rz volumio[1089]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 13:06:36 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:36 volumiopi-rz volumio[1089]: info: CoreStateMachine::startPlaybackTimer Mar 04 13:06:36 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:36 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioGetVisibleSources Mar 04 13:06:36 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 13:06:36 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 04 13:06:36 volumiopi-rz volumio[1089]: info: [ytmusic-play] clearAddPlayTrack: ytmusic/song@explodeTrackData:o=%7B%22type%22%3A%22song%22%2C%22title%22%3A%22Relaxing%20Music%22%2C%22artist%22%3A%22Soothing%20Sounds%22%2C%22album%22%3A%22Relaxing%20Music%22%2C%22albumart%22%3A%22https%3A%2F%2Flh3.googleusercontent.com%2FoK0i2XW3fiMwep3FvawAZOhIwqlQvZ3-JDZqQ85NosyDEetyZiM-xSn9AgqU1gbkRUxf1mOKpQbK625avw%3Dw701-h701-l90-rj%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%2C%22autoplayContext%22%3A%7B%22fetchEndpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%7D%7D Mar 04 13:06:36 volumiopi-rz mpd[20335]: Mar 04 13:06 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 04 13:06:36 volumiopi-rz systemd[1]: Started Music Player Daemon. Mar 04 13:06:36 volumiopi-rz sudo[20240]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:36 volumiopi-rz sudo[20321]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:36 volumiopi-rz sudo[20291]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:36 volumiopi-rz sudo[20225]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:36 volumiopi-rz volumio[1089]: error: MPD error: The expression evaluated to a falsy value: Mar 04 13:06:36 volumiopi-rz volumio[1089]: assert.ok(self.idling) Mar 04 13:06:36 volumiopi-rz volumio[1089]: error: The expression evaluated to a falsy value: Mar 04 13:06:36 volumiopi-rz volumio[1089]: assert.ok(self.idling) Mar 04 13:06:36 volumiopi-rz volumio[1089]: error: MPD error: The expression evaluated to a falsy value: Mar 04 13:06:36 volumiopi-rz volumio[1089]: assert.ok(self.idling) Mar 04 13:06:36 volumiopi-rz volumio[1089]: error: The expression evaluated to a falsy value: Mar 04 13:06:36 volumiopi-rz volumio[1089]: assert.ok(self.idling) Mar 04 13:06:36 volumiopi-rz volumio[1089]: error: MPD error: The expression evaluated to a falsy value: Mar 04 13:06:36 volumiopi-rz volumio[1089]: assert.ok(self.idling) Mar 04 13:06:36 volumiopi-rz volumio[1089]: error: The expression evaluated to a falsy value: Mar 04 13:06:36 volumiopi-rz volumio[1089]: assert.ok(self.idling) Mar 04 13:06:36 volumiopi-rz volumio[1089]: error: updateQueue error: null Mar 04 13:06:36 volumiopi-rz systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Mar 04 13:06:36 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:36 volumiopi-rz volumio[1089]: info: TidalConnect service stoped! Mar 04 13:06:36 volumiopi-rz volumio[1089]: info: TidalConnect service stoped! Mar 04 13:06:36 volumiopi-rz volumio[20367]: cset: --> shielding system active with Mar 04 13:06:36 volumiopi-rz volumio[20367]: cset: "system" cpuset of CPUSPEC(1-3) with 240 tasks running Mar 04 13:06:36 volumiopi-rz volumio[20367]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Mar 04 13:06:36 volumiopi-rz systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Mar 04 13:06:36 volumiopi-rz systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 04 13:06:36 volumiopi-rz systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 809. Mar 04 13:06:36 volumiopi-rz systemd[1]: Stopped go-librespot Daemon. Mar 04 13:06:36 volumiopi-rz volumio[1089]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Mar 04 13:06:36 volumiopi-rz volumio[1089]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Mar 04 13:06:36 volumiopi-rz systemd[1]: Started go-librespot Daemon. Mar 04 13:06:36 volumiopi-rz go-librespot[20386]: Librespot-go daemon starting... Mar 04 13:06:36 volumiopi-rz sudo[20392]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Mar 04 13:06:36 volumiopi-rz sudo[20392]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:36 volumiopi-rz go-librespot[20386]: time="2025-03-04T13:06:36+01:00" level=info msg="generated new device id: f0e7b4f7837d3e55ee3aaa808b3f787b3fa11fc5" Mar 04 13:06:36 volumiopi-rz go-librespot[20386]: time="2025-03-04T13:06:36+01:00" level=debug msg="stored credentials found for fabian.mundry" Mar 04 13:06:36 volumiopi-rz systemd[1]: Started Volumio Tidal Connect Service. Mar 04 13:06:36 volumiopi-rz sudo[20392]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:36 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:36 volumiopi-rz go-librespot[20386]: time="2025-03-04T13:06:36+01:00" level=debug msg="new websocket client" Mar 04 13:06:36 volumiopi-rz volumio[1089]: info: Connection to go-librespot Websocket established Mar 04 13:06:36 volumiopi-rz go-librespot[20386]: time="2025-03-04T13:06:36+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 13:06:36 volumiopi-rz go-librespot[20386]: time="2025-03-04T13:06:36+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 13:06:36 volumiopi-rz go-librespot[20386]: time="2025-03-04T13:06:36+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 13:06:36 volumiopi-rz go-librespot[20386]: time="2025-03-04T13:06:36+01:00" level=debug msg="zeroconf server listening on port 41637" Mar 04 13:06:37 volumiopi-rz go-librespot[20386]: time="2025-03-04T13:06:37+01:00" level=debug msg="obtained new client token: AAAKTT+OeE07gwemrfdMqVEB87fnefLR/1qb0Detm2iCUqXuOhiza/+qpn8xR9EZNTGkvf1tpzdGMiEwzJxuVBjRWz1OOusYm4G17tAA7pTHDYEEGveDxEFAyE4239HbxgoxUJE0XmhDVUT5qgD4bK3x3bDXYJcO18Bs4Kg+HtEYF62JUI/+Zrf+qLZhugk0Yl16155fg9xg3JhU8gkBw56aQ9fqKnY8kMZ8nz0y1y+8GyqfeJMU5KDrt879YU4=" Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: Executing endpoint tc_getconfig Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Mar 04 13:06:37 volumiopi-rz vtcs[20401]: STARTING TidalConnect services, version: 1.4.0.34 Mar 04 13:06:37 volumiopi-rz go-librespot[20386]: time="2025-03-04T13:06:37+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 04 13:06:37 volumiopi-rz vtcs[20401]: STARTED TidalConnect services. Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: Executing endpoint tc_connect Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: Connecting to TidalConnect Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CoreCommandRouter::servicePushState Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CoreStateMachine::pushState Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPushState Mar 04 13:06:37 volumiopi-rz go-librespot[20386]: time="2025-03-04T13:06:37+01:00" level=debug msg="completed keyexchange" Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output update for this device Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current ytmusic Received tidalconnect Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CoreCommandRouter::servicePushState Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CoreStateMachine::pushState Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPushState Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output update for this device Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current ytmusic Received tidalconnect Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 04 13:06:37 volumiopi-rz volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 04 13:06:37 volumiopi-rz volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: TidalConnect service stoped! Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: TidalConnect service stoped! Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: TidalConnect service stoped! Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CoreStateMachine::getcurrentVolume Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: TidalConnect service stoped! Mar 04 13:06:37 volumiopi-rz go-librespot[20386]: time="2025-03-04T13:06:37+01:00" level=debug msg="completed challenge" Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Mar 04 13:06:37 volumiopi-rz go-librespot[20386]: time="2025-03-04T13:06:37+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 04 13:06:37 volumiopi-rz systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 13:06:37 volumiopi-rz systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: VolumeController:: Volume=86 Mute =false Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CoreStateMachine::pushState Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPushState Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output update for this device Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CoreStateMachine::updateTrackBlock Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrackBlock Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: Connection to go-librespot Websocket closed Mar 04 13:06:37 volumiopi-rz sudo[20441]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Mar 04 13:06:37 volumiopi-rz sudo[20441]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 04 13:06:37 volumiopi-rz volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 04 13:06:37 volumiopi-rz sudo[20441]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: VolumeController:: Volume=86 Mute =false Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CoreStateMachine::pushState Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPushState Mar 04 13:06:37 volumiopi-rz sudo[20446]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output update for this device Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output Mar 04 13:06:37 volumiopi-rz sudo[20446]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 04 13:06:37 volumiopi-rz sudo[20446]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:37 volumiopi-rz volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 04 13:06:37 volumiopi-rz volumio[1089]: info: TidalConnect service stoped! Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: TidalConnect service stoped! Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: FusionDsp - eq1: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 25 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq2: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 40 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq3: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 63 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq4: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 100 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq5: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 160 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq6: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 250 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq7: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 400 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq8: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 630 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq9: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 1000 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq10: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 1600 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq11: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 2500 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq12: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 4000 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq13: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 6300 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq14: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 10000 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq15: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 16000 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: FusionDsp - eq1: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 25 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq2: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 40 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq3: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 63 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq4: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 100 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq5: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 160 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq6: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 250 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq7: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 400 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq8: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 630 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq9: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 1000 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq10: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 1600 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq11: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 2500 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq12: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 4000 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq13: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 6300 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq14: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 10000 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq15: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 16000 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: error: FusionDsp - WebSocket error: [object Object] Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Mar 04 13:06:38 volumiopi-rz sudo[20458]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Mar 04 13:06:38 volumiopi-rz sudo[20458]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:38 volumiopi-rz sudo[20458]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPlay Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: CoreStateMachine::play index undefined Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: CoreStateMachine::startPlaybackTimer Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioGetVisibleSources Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: [ytmusic-play] clearAddPlayTrack: ytmusic/song@explodeTrackData:o=%7B%22type%22%3A%22song%22%2C%22title%22%3A%22Relaxing%20Music%22%2C%22artist%22%3A%22Soothing%20Sounds%22%2C%22album%22%3A%22Relaxing%20Music%22%2C%22albumart%22%3A%22https%3A%2F%2Flh3.googleusercontent.com%2FoK0i2XW3fiMwep3FvawAZOhIwqlQvZ3-JDZqQ85NosyDEetyZiM-xSn9AgqU1gbkRUxf1mOKpQbK625avw%3Dw701-h701-l90-rj%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%2C%22autoplayContext%22%3A%7B%22fetchEndpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%7D%7D Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: TidalConnect service stoped! Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: TidalConnect service stoped! Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Mar 04 13:06:38 volumiopi-rz sudo[20470]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Mar 04 13:06:38 volumiopi-rz sudo[20470]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:38 volumiopi-rz sudo[20470]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: FusionDsp - eq1: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 25 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq2: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 40 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq3: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 63 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq4: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 100 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq5: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 160 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq6: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 250 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq7: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 400 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq8: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 630 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq9: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 1000 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq10: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 1600 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq11: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 2500 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq12: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 4000 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq13: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 6300 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq14: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 10000 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq15: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 16000 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: error: FusionDsp - WebSocket error: [object Object] Mar 04 13:06:38 volumiopi-rz volumio[1089]: info: FusionDsp - eq1: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 25 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq2: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 40 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq3: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 63 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq4: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 100 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq5: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 160 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq6: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 250 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq7: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 400 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq8: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 630 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq9: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 1000 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq10: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 1600 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq11: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 2500 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq12: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 4000 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq13: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 6300 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq14: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 10000 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: eq15: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:38 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:38 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:38 volumiopi-rz volumio[1089]: freq: 16000 Mar 04 13:06:38 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:38 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:38 volumiopi-rz volumio[1089]: error: FusionDsp - WebSocket error: [object Object] Mar 04 13:06:39 volumiopi-rz volumio[1089]: info: TidalConnect service started! Mar 04 13:06:39 volumiopi-rz volumio[1089]: info: Getting Spotify volume Mar 04 13:06:39 volumiopi-rz volumio[1089]: (node:1089) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:39 volumiopi-rz volumio[1089]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 04 13:06:39 volumiopi-rz volumio[1089]: (node:1089) 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: 65) Mar 04 13:06:39 volumiopi-rz volumio[1089]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Mar 04 13:06:39 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioGetState Mar 04 13:06:39 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:39 volumiopi-rz volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 04 13:06:40 volumiopi-rz systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 04 13:06:40 volumiopi-rz systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 810. Mar 04 13:06:40 volumiopi-rz systemd[1]: Stopped go-librespot Daemon. Mar 04 13:06:40 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:40 volumiopi-rz go-librespot[20475]: Librespot-go daemon starting... Mar 04 13:06:40 volumiopi-rz systemd[1]: Started go-librespot Daemon. Mar 04 13:06:40 volumiopi-rz go-librespot[20475]: time="2025-03-04T13:06:40+01:00" level=info msg="generated new device id: 208e0056a853ee3ee15638c34692cb4da184bd89" Mar 04 13:06:40 volumiopi-rz go-librespot[20475]: time="2025-03-04T13:06:40+01:00" level=debug msg="stored credentials found for fabian.mundry" Mar 04 13:06:40 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:40 volumiopi-rz volumio[1089]: info: TidalConnect service started! Mar 04 13:06:40 volumiopi-rz volumio[1089]: info: TidalConnect service started! Mar 04 13:06:40 volumiopi-rz go-librespot[20475]: time="2025-03-04T13:06:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 13:06:40 volumiopi-rz go-librespot[20475]: time="2025-03-04T13:06:40+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 13:06:40 volumiopi-rz go-librespot[20475]: time="2025-03-04T13:06:40+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 13:06:40 volumiopi-rz go-librespot[20475]: time="2025-03-04T13:06:40+01:00" level=debug msg="zeroconf server listening on port 37095" Mar 04 13:06:41 volumiopi-rz go-librespot[20475]: time="2025-03-04T13:06:41+01:00" level=debug msg="obtained new client token: AAAJGk8uyhITZdd5Ncx1GW10OzfuQEhL7WrEkvk4i1SAZJ1IgdtFvgWxl93Q9fMQUAr2gPRcK26VfhtlfoaBWlICBkIf05/wcyCu5LytU9NhEC5QpemNNkhw7jA4Ji3W0VzQGYB2KeUcKguT9PZSxe/OtuIrZQnzhePIDLj87OQI/8ZclccCYVqzY5wO5eN2gevumT0HYRL0t6TSIGWsYf9ei0K61c+U+jkyQZdqbmBM+8Gm4FithxyFmFRa" Mar 04 13:06:41 volumiopi-rz go-librespot[20475]: time="2025-03-04T13:06:41+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070 (error: dial tcp 34.158.1.133:4070: connect: connection refused), retrying with a different AP" Mar 04 13:06:41 volumiopi-rz go-librespot[20475]: time="2025-03-04T13:06:41+01:00" level=info msg="connected to ap-gew4.spotify.com:443" Mar 04 13:06:41 volumiopi-rz go-librespot[20475]: time="2025-03-04T13:06:41+01:00" level=debug msg="completed keyexchange" Mar 04 13:06:41 volumiopi-rz volumio[1089]: info: TidalConnect service started! Mar 04 13:06:41 volumiopi-rz volumio[1089]: info: TidalConnect service started! Mar 04 13:06:41 volumiopi-rz go-librespot[20475]: time="2025-03-04T13:06:41+01:00" level=debug msg="completed challenge" Mar 04 13:06:41 volumiopi-rz go-librespot[20475]: time="2025-03-04T13:06:41+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 04 13:06:41 volumiopi-rz systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 13:06:41 volumiopi-rz systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 13:06:43 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:43 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:44 volumiopi-rz systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 04 13:06:44 volumiopi-rz systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 811. Mar 04 13:06:44 volumiopi-rz systemd[1]: Stopped go-librespot Daemon. Mar 04 13:06:44 volumiopi-rz systemd[1]: Started go-librespot Daemon. Mar 04 13:06:44 volumiopi-rz go-librespot[20486]: Librespot-go daemon starting... Mar 04 13:06:44 volumiopi-rz go-librespot[20486]: time="2025-03-04T13:06:44+01:00" level=info msg="generated new device id: 160c84faa3c0fcba1aeed7ba4fd69fc306f8b7e9" Mar 04 13:06:44 volumiopi-rz go-librespot[20486]: time="2025-03-04T13:06:44+01:00" level=debug msg="stored credentials found for fabian.mundry" Mar 04 13:06:45 volumiopi-rz go-librespot[20486]: time="2025-03-04T13:06:45+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 13:06:45 volumiopi-rz go-librespot[20486]: time="2025-03-04T13:06:45+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 13:06:45 volumiopi-rz go-librespot[20486]: time="2025-03-04T13:06:45+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 13:06:45 volumiopi-rz go-librespot[20486]: time="2025-03-04T13:06:45+01:00" level=debug msg="zeroconf server listening on port 44771" Mar 04 13:06:45 volumiopi-rz go-librespot[20486]: time="2025-03-04T13:06:45+01:00" level=debug msg="obtained new client token: AABN/BNY0E86mjgxihDonh0HDO/9KdFD/VjYDTn/Qa40PTd+weioZh0uwZZia2PgJWX35kawbLhc1sIqPNDC4uomiHsqytzUd+e7ks0sOimSmmI5onW5/OHe4rlsmTBWucfwCUjrl7xwzrKffVtqPhiMs0Zmi5XU02fKxJj7xeDMQ+8k/rmgljf+N1HalhnkdvOITPgkMNM0J+Q8IpYoyrPSD9hUTyvbvW9UzpqlPj9X1BbvHop3J8hC1rY/" Mar 04 13:06:45 volumiopi-rz go-librespot[20486]: time="2025-03-04T13:06:45+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070 (error: dial tcp 34.158.1.133:4070: connect: connection refused), retrying with a different AP" Mar 04 13:06:45 volumiopi-rz go-librespot[20486]: time="2025-03-04T13:06:45+01:00" level=info msg="connected to ap-gew4.spotify.com:443" Mar 04 13:06:45 volumiopi-rz go-librespot[20486]: time="2025-03-04T13:06:45+01:00" level=debug msg="completed keyexchange" Mar 04 13:06:45 volumiopi-rz go-librespot[20486]: time="2025-03-04T13:06:45+01:00" level=debug msg="completed challenge" Mar 04 13:06:45 volumiopi-rz go-librespot[20486]: time="2025-03-04T13:06:45+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 04 13:06:45 volumiopi-rz systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 13:06:45 volumiopi-rz systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 13:06:45 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPlay Mar 04 13:06:45 volumiopi-rz volumio[1089]: info: CoreStateMachine::play index undefined Mar 04 13:06:45 volumiopi-rz volumio[1089]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 13:06:45 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:45 volumiopi-rz volumio[1089]: info: CoreStateMachine::startPlaybackTimer Mar 04 13:06:45 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:45 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioGetVisibleSources Mar 04 13:06:45 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 13:06:45 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 04 13:06:45 volumiopi-rz volumio[1089]: info: [ytmusic-play] clearAddPlayTrack: ytmusic/song@explodeTrackData:o=%7B%22type%22%3A%22song%22%2C%22title%22%3A%22Relaxing%20Music%22%2C%22artist%22%3A%22Soothing%20Sounds%22%2C%22album%22%3A%22Relaxing%20Music%22%2C%22albumart%22%3A%22https%3A%2F%2Flh3.googleusercontent.com%2FoK0i2XW3fiMwep3FvawAZOhIwqlQvZ3-JDZqQ85NosyDEetyZiM-xSn9AgqU1gbkRUxf1mOKpQbK625avw%3Dw701-h701-l90-rj%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%2C%22autoplayContext%22%3A%7B%22fetchEndpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%7D%7D Mar 04 13:06:46 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:46 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:47 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPlay Mar 04 13:06:47 volumiopi-rz volumio[1089]: info: CoreStateMachine::play index undefined Mar 04 13:06:47 volumiopi-rz volumio[1089]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 13:06:47 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:47 volumiopi-rz volumio[1089]: info: CoreStateMachine::startPlaybackTimer Mar 04 13:06:47 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:47 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioGetVisibleSources Mar 04 13:06:47 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 13:06:47 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 04 13:06:47 volumiopi-rz volumio[1089]: info: [ytmusic-play] clearAddPlayTrack: ytmusic/song@explodeTrackData:o=%7B%22type%22%3A%22song%22%2C%22title%22%3A%22Relaxing%20Music%22%2C%22artist%22%3A%22Soothing%20Sounds%22%2C%22album%22%3A%22Relaxing%20Music%22%2C%22albumart%22%3A%22https%3A%2F%2Flh3.googleusercontent.com%2FoK0i2XW3fiMwep3FvawAZOhIwqlQvZ3-JDZqQ85NosyDEetyZiM-xSn9AgqU1gbkRUxf1mOKpQbK625avw%3Dw701-h701-l90-rj%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%2C%22autoplayContext%22%3A%7B%22fetchEndpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%7D%7D Mar 04 13:06:48 volumiopi-rz systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 04 13:06:48 volumiopi-rz systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 812. Mar 04 13:06:48 volumiopi-rz systemd[1]: Stopped go-librespot Daemon. Mar 04 13:06:48 volumiopi-rz systemd[1]: Started go-librespot Daemon. Mar 04 13:06:48 volumiopi-rz go-librespot[20510]: Librespot-go daemon starting... Mar 04 13:06:48 volumiopi-rz go-librespot[20510]: time="2025-03-04T13:06:48+01:00" level=info msg="generated new device id: 08dde91e89bfb0f838531c8b290ad8e54c69e562" Mar 04 13:06:48 volumiopi-rz go-librespot[20510]: time="2025-03-04T13:06:48+01:00" level=debug msg="stored credentials found for fabian.mundry" Mar 04 13:06:49 volumiopi-rz go-librespot[20510]: time="2025-03-04T13:06:49+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 13:06:49 volumiopi-rz go-librespot[20510]: time="2025-03-04T13:06:49+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 13:06:49 volumiopi-rz go-librespot[20510]: time="2025-03-04T13:06:49+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 13:06:49 volumiopi-rz go-librespot[20510]: time="2025-03-04T13:06:49+01:00" level=debug msg="zeroconf server listening on port 44047" Mar 04 13:06:49 volumiopi-rz go-librespot[20510]: time="2025-03-04T13:06:49+01:00" level=debug msg="obtained new client token: AAB3PWhNH6UyEZ9/5cWBh4OqtloS70gyuDMhLLw07zINbmLt6JUAMV4cs3IWCnjN3nf4l2OmUEv85IZ1wWWDYlRSTrh0ck7j7/RQvLyvZC2KL+qe4jKgGCCTasZ95fsWrQBH8t0zutfNbgo61i5NFccvL5emwrK9Ejou5hNseVl6HWxmC0Df80iWw3NBXjKanMXGJz10ojf2zoFkXtscESM3IX/k1ygV2SFm8aBq4UQZ6Uyp8UTxcjcomHLQ" Mar 04 13:06:49 volumiopi-rz go-librespot[20510]: time="2025-03-04T13:06:49+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 04 13:06:49 volumiopi-rz go-librespot[20510]: time="2025-03-04T13:06:49+01:00" level=debug msg="completed keyexchange" Mar 04 13:06:49 volumiopi-rz go-librespot[20510]: time="2025-03-04T13:06:49+01:00" level=debug msg="completed challenge" Mar 04 13:06:49 volumiopi-rz go-librespot[20510]: time="2025-03-04T13:06:49+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 04 13:06:49 volumiopi-rz systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 13:06:49 volumiopi-rz systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 13:06:49 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:49 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:52 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:52 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:52 volumiopi-rz systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 04 13:06:52 volumiopi-rz systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 813. Mar 04 13:06:52 volumiopi-rz systemd[1]: Stopped go-librespot Daemon. Mar 04 13:06:52 volumiopi-rz systemd[1]: Started go-librespot Daemon. Mar 04 13:06:52 volumiopi-rz go-librespot[20561]: Librespot-go daemon starting... Mar 04 13:06:52 volumiopi-rz go-librespot[20561]: time="2025-03-04T13:06:52+01:00" level=info msg="generated new device id: bbf815e206182b2d528a1b9ffde3322ac41055c2" Mar 04 13:06:52 volumiopi-rz go-librespot[20561]: time="2025-03-04T13:06:52+01:00" level=debug msg="stored credentials found for fabian.mundry" Mar 04 13:06:53 volumiopi-rz go-librespot[20561]: time="2025-03-04T13:06:53+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 13:06:53 volumiopi-rz go-librespot[20561]: time="2025-03-04T13:06:53+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 13:06:53 volumiopi-rz go-librespot[20561]: time="2025-03-04T13:06:53+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 13:06:53 volumiopi-rz go-librespot[20561]: time="2025-03-04T13:06:53+01:00" level=debug msg="zeroconf server listening on port 36931" Mar 04 13:06:53 volumiopi-rz go-librespot[20561]: time="2025-03-04T13:06:53+01:00" level=debug msg="obtained new client token: AAD0UH+fY2SAq7C3VSoUXHyeRSkWsXSJLyIlZ0d0ja0t98Bep0LmqYvUW8h/uLhAOqXRzigVgQPHQRT12k08iEE15Gxo6cm0StObkhZVVNVIbRhofJULbuCpfPbADwgh8cKOg6l7/tcX/rGwPfSgmb8NFSkitkDw24moJn5KJfjsGmH+aMh6lN9Lt59XH7dKSQ1KhPp1pXijXbzbrSCM534tyY5HyLG2rPFEzdTOhBDBJTPcRYs+gsPP5wcK" Mar 04 13:06:53 volumiopi-rz go-librespot[20561]: time="2025-03-04T13:06:53+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 04 13:06:53 volumiopi-rz go-librespot[20561]: time="2025-03-04T13:06:53+01:00" level=debug msg="completed keyexchange" Mar 04 13:06:53 volumiopi-rz go-librespot[20561]: time="2025-03-04T13:06:53+01:00" level=debug msg="completed challenge" Mar 04 13:06:53 volumiopi-rz go-librespot[20561]: time="2025-03-04T13:06:53+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 04 13:06:53 volumiopi-rz systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 13:06:53 volumiopi-rz systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 13:06:55 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:55 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:56 volumiopi-rz volumio[1089]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Mar 04 13:06:56 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Mar 04 13:06:56 volumiopi-rz volumio[1089]: info: Preparing to save Alsa Options, stopping services first Mar 04 13:06:56 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioGetState Mar 04 13:06:56 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:56 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPause Mar 04 13:06:56 volumiopi-rz volumio[1089]: info: CoreStateMachine::pause Mar 04 13:06:56 volumiopi-rz volumio[1089]: info: Saving Audio Output to: {"output_device":{"value":"0","label":"HDMI Out"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Mar 04 13:06:56 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 04 13:06:56 volumiopi-rz volumio[1089]: info: Enabling PI HDMI Output Mar 04 13:06:56 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 04 13:06:56 volumiopi-rz volumio[1089]: info: Found match in Cards Database: setting mixer PCM for card HDMI Out Mar 04 13:06:56 volumiopi-rz vtcs[20401]: [2025-03-04 13:06:56.867] [tisoc] [error] [SpkconServer.cpp:376] recv error. socket disconnected Mar 04 13:06:56 volumiopi-rz vtcs[20401]: [2025-03-04 13:06:56.868] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE Mar 04 13:06:56 volumiopi-rz sudo[20590]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 13:06:56 volumiopi-rz sudo[20590]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:56 volumiopi-rz systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 04 13:06:56 volumiopi-rz systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 814. Mar 04 13:06:56 volumiopi-rz systemd[1]: Stopping Volumio Tidal Connect Service... Mar 04 13:06:56 volumiopi-rz systemd[1]: Stopped go-librespot Daemon. Mar 04 13:06:56 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioUpdateVolumeSettings Mar 04 13:06:56 volumiopi-rz volumio[1089]: info: Updating Volume Controller Parameters: Device: 0 Name: HDMI Out Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Mar 04 13:06:56 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Mar 04 13:06:56 volumiopi-rz volumio[1089]: info: Disabling external Volume Control Mar 04 13:06:56 volumiopi-rz volumio[1089]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 04 13:06:56 volumiopi-rz volumio[1089]: info: Preparing to generate the ALSA configuration file Mar 04 13:06:56 volumiopi-rz systemd[1]: Started go-librespot Daemon. Mar 04 13:06:56 volumiopi-rz go-librespot[20594]: Librespot-go daemon starting... Mar 04 13:06:56 volumiopi-rz systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Mar 04 13:06:56 volumiopi-rz systemd[1]: vtcs.service: Succeeded. Mar 04 13:06:57 volumiopi-rz systemd[1]: Stopped Volumio Tidal Connect Service. Mar 04 13:06:57 volumiopi-rz go-librespot[20594]: time="2025-03-04T13:06:57+01:00" level=info msg="generated new device id: 99bae6917bf92ae8f6f85fb7a9bcefc28463ee87" Mar 04 13:06:57 volumiopi-rz go-librespot[20594]: time="2025-03-04T13:06:57+01:00" level=debug msg="stored credentials found for fabian.mundry" Mar 04 13:06:57 volumiopi-rz sudo[20590]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:57 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: Reading ALSA contributions from plugins. Mar 04 13:06:57 volumiopi-rz sudo[20604]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 13:06:57 volumiopi-rz sudo[20604]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: Raspberry PI HDMI Output Enabled Mar 04 13:06:57 volumiopi-rz sudo[20604]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: VolumeController:: Volume=86 Mute =false Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreStateMachine::pushState Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPushState Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output update for this device Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output Mar 04 13:06:57 volumiopi-rz sudo[20609]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl store Mar 04 13:06:57 volumiopi-rz sudo[20609]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:57 volumiopi-rz sudo[20609]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 04 13:06:57 volumiopi-rz go-librespot[20594]: time="2025-03-04T13:06:57+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 13:06:57 volumiopi-rz go-librespot[20594]: time="2025-03-04T13:06:57+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 13:06:57 volumiopi-rz go-librespot[20594]: time="2025-03-04T13:06:57+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 13:06:57 volumiopi-rz volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: Alsa Settings successfully stored Mar 04 13:06:57 volumiopi-rz go-librespot[20594]: time="2025-03-04T13:06:57+01:00" level=debug msg="zeroconf server listening on port 38819" Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 04 13:06:57 volumiopi-rz go-librespot[20594]: time="2025-03-04T13:06:57+01:00" level=debug msg="obtained new client token: AADodw5umW586iaN9rGXCnFgqhbDS7NZVv5X2wD1i5InzhtDQ5fY8SzwOFADLjpX/383LdeGzvH08MjStcQ114BDqwMKGeMXMvPiXnqYChpO+jbb1bu1PbXVBgvRISytlBhzcyEN5n6HaPD7nUldy3sJbnRVReYDdhtVaC5kNf/nDw5mNSbzL2Fk7fhFvx1jnKPX8k1GKumbHEdx3W1w7CFhj2WLtLSVUtzly0OnREWOetrKqNiLjRkCosF5" Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Mar 04 13:06:57 volumiopi-rz go-librespot[20594]: time="2025-03-04T13:06:57+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Mar 04 13:06:57 volumiopi-rz go-librespot[20594]: time="2025-03-04T13:06:57+01:00" level=debug msg="completed keyexchange" Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: Asound.conf file written Mar 04 13:06:57 volumiopi-rz sudo[20622]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Mar 04 13:06:57 volumiopi-rz sudo[20622]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:57 volumiopi-rz sudo[20622]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: Output device has changed, restarting MPD Mar 04 13:06:57 volumiopi-rz sudo[20627]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 13:06:57 volumiopi-rz sudo[20627]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:57 volumiopi-rz sudo[20627]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: Output device has changed, restarting Shairport Sync Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 13:06:57 volumiopi-rz sudo[20630]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 13:06:57 volumiopi-rz sudo[20630]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:57 volumiopi-rz systemd[1]: musicservicesshield.service: Succeeded. Mar 04 13:06:57 volumiopi-rz systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Mar 04 13:06:57 volumiopi-rz systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Mar 04 13:06:57 volumiopi-rz systemd[1]: Stopping Music Player Daemon... Mar 04 13:06:57 volumiopi-rz systemd[1]: mpd.service: Succeeded. Mar 04 13:06:57 volumiopi-rz systemd[1]: Stopped Music Player Daemon. Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:57 volumiopi-rz systemd[1]: Starting Music Player Daemon... Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: Output device has changed, restarting MPD Mar 04 13:06:57 volumiopi-rz sudo[20639]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 13:06:57 volumiopi-rz sudo[20639]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:57 volumiopi-rz sudo[20639]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:57 volumiopi-rz sudo[20643]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 13:06:57 volumiopi-rz sudo[20643]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:57 volumiopi-rz sudo[20635]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 13:06:57 volumiopi-rz sudo[20635]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:57 volumiopi-rz sudo[20643]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:57 volumiopi-rz sudo[20635]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: Output device has changed, restarting Shairport Sync Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 13:06:57 volumiopi-rz sudo[20648]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 13:06:57 volumiopi-rz sudo[20648]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:57 volumiopi-rz systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Mar 04 13:06:57 volumiopi-rz systemd[1]: mpd.service: Succeeded. Mar 04 13:06:57 volumiopi-rz systemd[1]: Stopped Music Player Daemon. Mar 04 13:06:57 volumiopi-rz systemd[1]: Starting Music Player Daemon... Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:57 volumiopi-rz go-librespot[20594]: time="2025-03-04T13:06:57+01:00" level=debug msg="completed challenge" Mar 04 13:06:57 volumiopi-rz sudo[20653]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 13:06:57 volumiopi-rz sudo[20653]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:57 volumiopi-rz sudo[20653]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:57 volumiopi-rz go-librespot[20594]: time="2025-03-04T13:06:57+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 04 13:06:57 volumiopi-rz sudo[20659]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 13:06:57 volumiopi-rz sudo[20659]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:57 volumiopi-rz systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 13:06:57 volumiopi-rz sudo[20662]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 13:06:57 volumiopi-rz systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 13:06:57 volumiopi-rz sudo[20662]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:57 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:57 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:57 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:57 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:57 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:57 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:57 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:57 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: MPD Permissions set Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: MPD Permissions set Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: touch_display: Setting screensaver timeout to 120 seconds. Mar 04 13:06:57 volumiopi-rz sudo[20665]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 13:06:57 volumiopi-rz sudo[20665]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:57 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:58 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 13:06:58 volumiopi-rz sudo[20662]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:58 volumiopi-rz sudo[20659]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:58 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:58 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:58 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:58 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:58 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:58 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:58 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:58 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:58 volumiopi-rz sudo[20665]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:58 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 13:06:58 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 13:06:58 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:58 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:58 volumiopi-rz volumio[1089]: info: Starting Shairport Sync Mar 04 13:06:58 volumiopi-rz volumio[1089]: info: Starting Shairport Sync Mar 04 13:06:58 volumiopi-rz sudo[20679]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 13:06:58 volumiopi-rz sudo[20679]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:58 volumiopi-rz systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 04 13:06:58 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:58 volumiopi-rz systemd[1]: shairport-sync.service: Succeeded. Mar 04 13:06:58 volumiopi-rz sudo[20682]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 13:06:58 volumiopi-rz systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 04 13:06:58 volumiopi-rz sudo[20682]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:06:58 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:58 volumiopi-rz systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 04 13:06:58 volumiopi-rz sudo[20679]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:58 volumiopi-rz volumio[1089]: info: Shairport-Sync Started Mar 04 13:06:58 volumiopi-rz systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 04 13:06:58 volumiopi-rz systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Mar 04 13:06:58 volumiopi-rz systemd[1]: shairport-sync.service: Succeeded. Mar 04 13:06:58 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:58 volumiopi-rz systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 04 13:06:58 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 04 13:06:58 volumiopi-rz systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 04 13:06:58 volumiopi-rz sudo[20682]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:58 volumiopi-rz volumio[1089]: info: Shairport-Sync Started Mar 04 13:06:58 volumiopi-rz volumio[1089]: (node:1089) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pbeg listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Mar 04 13:06:58 volumiopi-rz volumio[1089]: (node:1089) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 meta listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Mar 04 13:06:58 volumiopi-rz volumio[1089]: (node:1089) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 prgr listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Mar 04 13:06:58 volumiopi-rz volumio[1089]: (node:1089) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pvol listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Mar 04 13:06:58 volumiopi-rz volumio[1089]: (node:1089) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pend listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Mar 04 13:06:58 volumiopi-rz volumio[1089]: info: FusionDsp - eq1: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:58 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:58 volumiopi-rz volumio[1089]: freq: 25 Mar 04 13:06:58 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:58 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:58 volumiopi-rz volumio[1089]: eq2: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:58 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:58 volumiopi-rz volumio[1089]: freq: 40 Mar 04 13:06:58 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:58 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:58 volumiopi-rz volumio[1089]: eq3: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:58 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:58 volumiopi-rz volumio[1089]: freq: 63 Mar 04 13:06:58 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:58 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:58 volumiopi-rz volumio[1089]: eq4: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:58 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:58 volumiopi-rz volumio[1089]: freq: 100 Mar 04 13:06:58 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:58 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:58 volumiopi-rz volumio[1089]: eq5: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:58 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:58 volumiopi-rz volumio[1089]: freq: 160 Mar 04 13:06:58 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:58 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:58 volumiopi-rz volumio[1089]: eq6: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:58 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:58 volumiopi-rz volumio[1089]: freq: 250 Mar 04 13:06:58 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:58 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:58 volumiopi-rz volumio[1089]: eq7: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:58 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:58 volumiopi-rz volumio[1089]: freq: 400 Mar 04 13:06:58 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:58 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:58 volumiopi-rz volumio[1089]: eq8: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:58 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:58 volumiopi-rz volumio[1089]: freq: 630 Mar 04 13:06:58 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:58 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:58 volumiopi-rz volumio[1089]: eq9: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:58 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:58 volumiopi-rz volumio[1089]: freq: 1000 Mar 04 13:06:58 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:58 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:58 volumiopi-rz volumio[1089]: eq10: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:58 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:58 volumiopi-rz volumio[1089]: freq: 1600 Mar 04 13:06:58 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:58 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:58 volumiopi-rz volumio[1089]: eq11: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:58 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:58 volumiopi-rz volumio[1089]: freq: 2500 Mar 04 13:06:58 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:58 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:58 volumiopi-rz volumio[1089]: eq12: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:58 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:58 volumiopi-rz volumio[1089]: freq: 4000 Mar 04 13:06:58 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:58 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:58 volumiopi-rz volumio[1089]: eq13: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:58 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:58 volumiopi-rz volumio[1089]: freq: 6300 Mar 04 13:06:58 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:58 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:58 volumiopi-rz volumio[1089]: eq14: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:58 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:58 volumiopi-rz volumio[1089]: freq: 10000 Mar 04 13:06:58 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:58 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:58 volumiopi-rz volumio[1089]: eq15: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:06:58 volumiopi-rz volumio[1089]: parameters: Mar 04 13:06:58 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:06:58 volumiopi-rz volumio[1089]: freq: 16000 Mar 04 13:06:58 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:06:58 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:06:58 volumiopi-rz volumio[1089]: error: FusionDsp - WebSocket error: [object Object] Mar 04 13:06:58 volumiopi-rz mpd[20658]: Mar 04 13:06 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 04 13:06:58 volumiopi-rz systemd[1]: Started Music Player Daemon. Mar 04 13:06:58 volumiopi-rz sudo[20630]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:58 volumiopi-rz sudo[20648]: pam_unix(sudo:session): session closed for user root Mar 04 13:06:58 volumiopi-rz volumio[1089]: error: MPD error: The expression evaluated to a falsy value: Mar 04 13:06:58 volumiopi-rz volumio[1089]: assert.ok(self.idling) Mar 04 13:06:58 volumiopi-rz volumio[1089]: error: The expression evaluated to a falsy value: Mar 04 13:06:58 volumiopi-rz volumio[1089]: assert.ok(self.idling) Mar 04 13:06:58 volumiopi-rz volumio[1089]: error: updateQueue error: null Mar 04 13:06:58 volumiopi-rz systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Mar 04 13:06:58 volumiopi-rz volumio[1089]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 04 13:06:58 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:06:58 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:06:59 volumiopi-rz volumio[20690]: cset: --> shielding system active with Mar 04 13:06:59 volumiopi-rz volumio[20690]: cset: "system" cpuset of CPUSPEC(1-3) with 235 tasks running Mar 04 13:06:59 volumiopi-rz volumio[20690]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Mar 04 13:06:59 volumiopi-rz systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: TidalConnect service stoped! Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: TidalConnect service stoped! Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Mar 04 13:07:00 volumiopi-rz sudo[20714]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Mar 04 13:07:00 volumiopi-rz sudo[20714]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:07:00 volumiopi-rz systemd[1]: Started Volumio Tidal Connect Service. Mar 04 13:07:00 volumiopi-rz sudo[20714]: pam_unix(sudo:session): session closed for user root Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: Executing endpoint tc_getconfig Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Mar 04 13:07:00 volumiopi-rz vtcs[20716]: STARTING TidalConnect services, version: 1.4.0.34 Mar 04 13:07:00 volumiopi-rz vtcs[20716]: STARTED TidalConnect services. Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: Executing endpoint tc_connect Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: Connecting to TidalConnect Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: CoreCommandRouter::servicePushState Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: CoreStateMachine::pushState Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPushState Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output update for this device Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current ytmusic Received tidalconnect Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: CoreCommandRouter::servicePushState Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: CoreStateMachine::pushState Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPushState Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output update for this device Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current ytmusic Received tidalconnect Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 04 13:07:00 volumiopi-rz volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 04 13:07:00 volumiopi-rz volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: TidalConnect service stoped! Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: CoreStateMachine::getcurrentVolume Mar 04 13:07:00 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: VolumeController:: Volume=86 Mute =false Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: CoreStateMachine::pushState Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPushState Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output update for this device Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: CoreStateMachine::updateTrackBlock Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrackBlock Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 04 13:07:01 volumiopi-rz volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: TidalConnect service stoped! Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: TidalConnect service stoped! Mar 04 13:07:01 volumiopi-rz systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 04 13:07:01 volumiopi-rz systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 815. Mar 04 13:07:01 volumiopi-rz systemd[1]: Stopped go-librespot Daemon. Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: TidalConnect service stoped! Mar 04 13:07:01 volumiopi-rz systemd[1]: Started go-librespot Daemon. Mar 04 13:07:01 volumiopi-rz go-librespot[20742]: Librespot-go daemon starting... Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: VolumeController:: Volume=86 Mute =false Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: CoreStateMachine::pushState Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPushState Mar 04 13:07:01 volumiopi-rz go-librespot[20742]: time="2025-03-04T13:07:01+01:00" level=info msg="generated new device id: 6b0c967db3383bdfe6e816582e3e5ad77e06d69a" Mar 04 13:07:01 volumiopi-rz go-librespot[20742]: time="2025-03-04T13:07:01+01:00" level=debug msg="stored credentials found for fabian.mundry" Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output update for this device Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: MRS: Pushing multiroomSync output Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 04 13:07:01 volumiopi-rz volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Mar 04 13:07:01 volumiopi-rz sudo[20764]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Mar 04 13:07:01 volumiopi-rz sudo[20764]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:07:01 volumiopi-rz sudo[20764]: pam_unix(sudo:session): session closed for user root Mar 04 13:07:01 volumiopi-rz sudo[20768]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Mar 04 13:07:01 volumiopi-rz sudo[20768]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 13:07:01 volumiopi-rz go-librespot[20742]: time="2025-03-04T13:07:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 13:07:01 volumiopi-rz go-librespot[20742]: time="2025-03-04T13:07:01+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 13:07:01 volumiopi-rz go-librespot[20742]: time="2025-03-04T13:07:01+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 13:07:01 volumiopi-rz go-librespot[20742]: time="2025-03-04T13:07:01+01:00" level=debug msg="zeroconf server listening on port 37611" Mar 04 13:07:01 volumiopi-rz sudo[20768]: pam_unix(sudo:session): session closed for user root Mar 04 13:07:01 volumiopi-rz go-librespot[20742]: time="2025-03-04T13:07:01+01:00" level=debug msg="obtained new client token: AAABL7xOKdbNAPEcElnoc7X4lNfyEBgHZlnDr20zjW5VAqotP206mUTv2h59lsk8C33j2TumhjRbXuLRTq3TuDmOMF2EKFtL9uoTbOG5AbTDDQ8akIR8XtdrRbpq5SZxB+iaeKEdsvfSqITcj7HvZDmjsLTEwg3FZSCHf111OEcZNMOYxZDGAMoKIKc1fRTNzGkUv8Dwoa0bn8dyIdbi4S/5ePkyECdKllkTCS11is4oQUIhleVGavmWoYIwzQc=" Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: FusionDsp - eq1: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 25 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq2: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 40 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq3: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 63 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq4: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 100 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq5: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 160 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq6: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 250 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq7: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 400 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq8: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 630 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq9: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 1000 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq10: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 1600 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq11: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 2500 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq12: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 4000 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq13: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 6300 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq14: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 10000 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq15: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 16000 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: FusionDsp - eq1: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 25 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq2: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 40 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq3: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 63 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq4: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 100 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq5: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 160 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq6: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 250 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq7: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 400 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq8: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 630 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq9: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 1000 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq10: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 1600 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq11: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 2500 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq12: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 4000 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq13: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 6300 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq14: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 10000 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: eq15: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:01 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:01 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:01 volumiopi-rz volumio[1089]: freq: 16000 Mar 04 13:07:01 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:01 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:01 volumiopi-rz volumio[1089]: error: FusionDsp - WebSocket error: [object Object] Mar 04 13:07:01 volumiopi-rz go-librespot[20742]: time="2025-03-04T13:07:01+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 04 13:07:01 volumiopi-rz go-librespot[20742]: time="2025-03-04T13:07:01+01:00" level=debug msg="completed keyexchange" Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:07:01 volumiopi-rz go-librespot[20742]: time="2025-03-04T13:07:01+01:00" level=debug msg="new websocket client" Mar 04 13:07:01 volumiopi-rz volumio[1089]: info: Connection to go-librespot Websocket established Mar 04 13:07:02 volumiopi-rz go-librespot[20742]: time="2025-03-04T13:07:02+01:00" level=debug msg="completed challenge" Mar 04 13:07:02 volumiopi-rz go-librespot[20742]: time="2025-03-04T13:07:02+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 04 13:07:02 volumiopi-rz systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 13:07:02 volumiopi-rz volumio[1089]: info: Connection to go-librespot Websocket closed Mar 04 13:07:02 volumiopi-rz systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 13:07:02 volumiopi-rz volumio[1089]: info: FusionDsp - eq1: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 25 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq2: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 40 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq3: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 63 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq4: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 100 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq5: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 160 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq6: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 250 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq7: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 400 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq8: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 630 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq9: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 1000 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq10: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 1600 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq11: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 2500 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq12: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 4000 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq13: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 6300 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq14: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 10000 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq15: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 16000 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: error: FusionDsp - WebSocket error: [object Object] Mar 04 13:07:02 volumiopi-rz volumio[1089]: info: FusionDsp - eq1: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 25 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq2: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 40 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq3: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 63 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq4: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 100 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq5: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 160 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq6: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 250 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq7: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 400 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq8: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 630 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq9: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 1000 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq10: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 1600 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq11: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 2500 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq12: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 4000 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq13: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 6300 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq14: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 10000 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: eq15: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Biquad Mar 04 13:07:02 volumiopi-rz volumio[1089]: parameters: Mar 04 13:07:02 volumiopi-rz volumio[1089]: type: Peaking Mar 04 13:07:02 volumiopi-rz volumio[1089]: freq: 16000 Mar 04 13:07:02 volumiopi-rz volumio[1089]: q: 1.85 Mar 04 13:07:02 volumiopi-rz volumio[1089]: gain: 0 Mar 04 13:07:02 volumiopi-rz volumio[1089]: error: FusionDsp - WebSocket error: [object Object] Mar 04 13:07:03 volumiopi-rz volumio[1089]: info: TidalConnect service started! Mar 04 13:07:03 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioPlay Mar 04 13:07:03 volumiopi-rz volumio[1089]: info: CoreStateMachine::play index undefined Mar 04 13:07:03 volumiopi-rz volumio[1089]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 13:07:03 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:07:03 volumiopi-rz volumio[1089]: info: CoreStateMachine::startPlaybackTimer Mar 04 13:07:03 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:07:03 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioGetVisibleSources Mar 04 13:07:03 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 13:07:03 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 04 13:07:03 volumiopi-rz volumio[1089]: info: [ytmusic-play] clearAddPlayTrack: ytmusic/song@explodeTrackData:o=%7B%22type%22%3A%22song%22%2C%22title%22%3A%22Relaxing%20Music%22%2C%22artist%22%3A%22Soothing%20Sounds%22%2C%22album%22%3A%22Relaxing%20Music%22%2C%22albumart%22%3A%22https%3A%2F%2Flh3.googleusercontent.com%2FoK0i2XW3fiMwep3FvawAZOhIwqlQvZ3-JDZqQ85NosyDEetyZiM-xSn9AgqU1gbkRUxf1mOKpQbK625avw%3Dw701-h701-l90-rj%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%2C%22autoplayContext%22%3A%7B%22fetchEndpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22gVic5E313IM%22%2C%22playlistId%22%3A%22RDAMVMgVic5E313IM%22%2C%22params%22%3A%22wAEB%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_ATV%22%7D%7D%7D Mar 04 13:07:04 volumiopi-rz volumio[1089]: info: TidalConnect service started! Mar 04 13:07:04 volumiopi-rz volumio[1089]: info: TidalConnect service started! Mar 04 13:07:04 volumiopi-rz volumio[1089]: info: Getting Spotify volume Mar 04 13:07:04 volumiopi-rz volumio[1089]: (node:1089) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:07:04 volumiopi-rz volumio[1089]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 04 13:07:04 volumiopi-rz volumio[1089]: (node:1089) 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: 66) Mar 04 13:07:04 volumiopi-rz volumio[1089]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Mar 04 13:07:04 volumiopi-rz volumio[1089]: info: CoreCommandRouter::volumioGetState Mar 04 13:07:04 volumiopi-rz volumio[1089]: info: CorePlayQueue::getTrack 0 Mar 04 13:07:04 volumiopi-rz volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 04 13:07:05 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:07:05 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:07:05 volumiopi-rz systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 04 13:07:05 volumiopi-rz systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 816. Mar 04 13:07:05 volumiopi-rz systemd[1]: Stopped go-librespot Daemon. Mar 04 13:07:05 volumiopi-rz systemd[1]: Started go-librespot Daemon. Mar 04 13:07:05 volumiopi-rz go-librespot[20776]: Librespot-go daemon starting... Mar 04 13:07:05 volumiopi-rz go-librespot[20776]: time="2025-03-04T13:07:05+01:00" level=info msg="generated new device id: bd8776cb24df0e52cdc1c0e7dac2b6de13cb0ed1" Mar 04 13:07:05 volumiopi-rz go-librespot[20776]: time="2025-03-04T13:07:05+01:00" level=debug msg="stored credentials found for fabian.mundry" Mar 04 13:07:05 volumiopi-rz go-librespot[20776]: time="2025-03-04T13:07:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 13:07:05 volumiopi-rz go-librespot[20776]: time="2025-03-04T13:07:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 13:07:05 volumiopi-rz go-librespot[20776]: time="2025-03-04T13:07:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 13:07:05 volumiopi-rz go-librespot[20776]: time="2025-03-04T13:07:05+01:00" level=debug msg="zeroconf server listening on port 43205" Mar 04 13:07:05 volumiopi-rz go-librespot[20776]: time="2025-03-04T13:07:05+01:00" level=debug msg="obtained new client token: AADSsp9PftEUaToQ5KEdqZOnHhWF9F/XojMJ+I9ximQZzEWRpRcZV+kT6utAZ+ZtX23OAGVWujFUuMURZgTaqtGYhBTKmi32kiAVwyXczJyBTrIRNmX01pTGJ77BlwR1PyqP+92eX4rXg09FqFmL+XR+Fr/Vqv6zEKdOQaupG29SHCTVMtw9zgDdedg4FYBwg1ap5AqLRlkOH4qrK+LXqwYGXsQy9s2pnEMP7OANXowhonvFdbKhDeEUdbdJSro=" Mar 04 13:07:05 volumiopi-rz go-librespot[20776]: time="2025-03-04T13:07:05+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 04 13:07:05 volumiopi-rz go-librespot[20776]: time="2025-03-04T13:07:05+01:00" level=debug msg="completed keyexchange" Mar 04 13:07:06 volumiopi-rz go-librespot[20776]: time="2025-03-04T13:07:06+01:00" level=debug msg="completed challenge" Mar 04 13:07:06 volumiopi-rz go-librespot[20776]: time="2025-03-04T13:07:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 04 13:07:06 volumiopi-rz systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 13:07:06 volumiopi-rz systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 13:07:08 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:07:08 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:07:09 volumiopi-rz systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 04 13:07:09 volumiopi-rz systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 817. Mar 04 13:07:09 volumiopi-rz systemd[1]: Stopped go-librespot Daemon. Mar 04 13:07:09 volumiopi-rz systemd[1]: Started go-librespot Daemon. Mar 04 13:07:09 volumiopi-rz go-librespot[20797]: Librespot-go daemon starting... Mar 04 13:07:09 volumiopi-rz go-librespot[20797]: time="2025-03-04T13:07:09+01:00" level=info msg="generated new device id: 4f12b60b697462405ddb5107a6fc5e05259bad4c" Mar 04 13:07:09 volumiopi-rz go-librespot[20797]: time="2025-03-04T13:07:09+01:00" level=debug msg="stored credentials found for fabian.mundry" Mar 04 13:07:09 volumiopi-rz go-librespot[20797]: time="2025-03-04T13:07:09+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 13:07:09 volumiopi-rz go-librespot[20797]: time="2025-03-04T13:07:09+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 13:07:09 volumiopi-rz go-librespot[20797]: time="2025-03-04T13:07:09+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 13:07:09 volumiopi-rz go-librespot[20797]: time="2025-03-04T13:07:09+01:00" level=debug msg="zeroconf server listening on port 42925" Mar 04 13:07:09 volumiopi-rz go-librespot[20797]: time="2025-03-04T13:07:09+01:00" level=debug msg="obtained new client token: AAD7SvxYJXDAK1FD7OiHrMYl2ctyxwoneqxwIzchrYOVKYrN9qqxB5OYu0J6TafCM+LZkHLYNt8jl1ML/h3qJmhhReRkjBBEvB160OKbmz/aAKPT3vgTHxLSv2knki7qc8w8OGyCb20p+Z9Zj7N4aY8NRLWINGqfkiNt1WK9gxMkQpUOr7tjPHg0bJfTReFIZmSn39NoMaurK3e++rH3DvBNeFjzN9s8+MQZHajoCQDt3n5OBD+3DFKiJTFQShg=" Mar 04 13:07:09 volumiopi-rz go-librespot[20797]: time="2025-03-04T13:07:09+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 04 13:07:09 volumiopi-rz go-librespot[20797]: time="2025-03-04T13:07:09+01:00" level=debug msg="completed keyexchange" Mar 04 13:07:10 volumiopi-rz go-librespot[20797]: time="2025-03-04T13:07:10+01:00" level=debug msg="completed challenge" Mar 04 13:07:10 volumiopi-rz go-librespot[20797]: time="2025-03-04T13:07:10+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 04 13:07:10 volumiopi-rz systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 13:07:10 volumiopi-rz systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 13:07:11 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:07:11 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:07:13 volumiopi-rz systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 04 13:07:13 volumiopi-rz systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 818. Mar 04 13:07:13 volumiopi-rz systemd[1]: Stopped go-librespot Daemon. Mar 04 13:07:13 volumiopi-rz systemd[1]: Started go-librespot Daemon. Mar 04 13:07:13 volumiopi-rz go-librespot[20808]: Librespot-go daemon starting... Mar 04 13:07:13 volumiopi-rz go-librespot[20808]: time="2025-03-04T13:07:13+01:00" level=info msg="generated new device id: 9d0abb26661311eb1e897cd3321c37122c89be23" Mar 04 13:07:13 volumiopi-rz go-librespot[20808]: time="2025-03-04T13:07:13+01:00" level=debug msg="stored credentials found for fabian.mundry" Mar 04 13:07:13 volumiopi-rz go-librespot[20808]: time="2025-03-04T13:07:13+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 13:07:13 volumiopi-rz go-librespot[20808]: time="2025-03-04T13:07:13+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 13:07:13 volumiopi-rz go-librespot[20808]: time="2025-03-04T13:07:13+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 13:07:13 volumiopi-rz go-librespot[20808]: time="2025-03-04T13:07:13+01:00" level=debug msg="zeroconf server listening on port 38871" Mar 04 13:07:13 volumiopi-rz go-librespot[20808]: time="2025-03-04T13:07:13+01:00" level=debug msg="obtained new client token: AAC89P0x8f+BmqH9PwFDqQ16paoEEENMTrrqoDGIiMJY3yzaqDl+iJRpOxthVRbY+NyF5+DGgdff5SO9NAU91J6sqJydFWm8k/UlEy+ilFRgTEaSRBg/nSiuM3FtbHIh3IiI43vL+E/W0foUNMUL8lhjWJuLPDve2KxgUapM6Rhqd8RmGbim1POqPrj/Tmi7B4mxiRHoYqTjIXXT1zOuifdZ7QOI/TZVc7XafT5c/XIZ79iMKByjJauMEsL+TZA=" Mar 04 13:07:13 volumiopi-rz go-librespot[20808]: time="2025-03-04T13:07:13+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 04 13:07:13 volumiopi-rz go-librespot[20808]: time="2025-03-04T13:07:13+01:00" level=debug msg="completed keyexchange" Mar 04 13:07:14 volumiopi-rz go-librespot[20808]: time="2025-03-04T13:07:14+01:00" level=debug msg="completed challenge" Mar 04 13:07:14 volumiopi-rz go-librespot[20808]: time="2025-03-04T13:07:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 04 13:07:14 volumiopi-rz systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 13:07:14 volumiopi-rz systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 13:07:14 volumiopi-rz volumio[1089]: info: Initializing connection to go-librespot Websocket Mar 04 13:07:14 volumiopi-rz volumio[1089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 13:07:16 volumiopi-rz volumio[1089]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay Mar 04 13:07:16 volumiopi-rz volumio[1089]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom Mar 04 13:07:16 volumiopi-rz volumio[1089]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 13:07:16 volumiopi-rz volumio[1089]: TypeError: Cannot read property 'then' of undefined Mar 04 13:07:16 volumiopi-rz volumio[1089]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) Mar 04 13:07:16 volumiopi-rz volumio[1089]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2273:30) Mar 04 13:07:16 volumiopi-rz volumio[1089]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1450:26) Mar 04 13:07:16 volumiopi-rz volumio[1089]: at Socket.emit (events.js:315:20) Mar 04 13:07:16 volumiopi-rz volumio[1089]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Mar 04 13:07:16 volumiopi-rz volumio[1089]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Mar 04 13:07:16 volumiopi-rz volumio[1089]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 13:07:16 volumiopi-rz sudo[20840]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-04 13:06 Mar 04 13:07:16 volumiopi-rz sudo[20840]: 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"