-- Logs begin at Mon 2024-04-08 23:56:34 +07, end at Tue 2024-04-09 00:42:24 +07. -- Apr 09 00:41:00 music-sever-luxman-dac-06 sudo[7838]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 09 00:41:00 music-sever-luxman-dac-06 sudo[7838]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:41:00 music-sever-luxman-dac-06 sudo[7838]: pam_unix(sudo:session): session closed for user root Apr 09 00:41:00 music-sever-luxman-dac-06 sudo[7841]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 09 00:41:00 music-sever-luxman-dac-06 sudo[7841]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:41:00 music-sever-luxman-dac-06 sudo[7841]: pam_unix(sudo:session): session closed for user root Apr 09 00:41:00 music-sever-luxman-dac-06 volumio[937]: verbose: New Socket.io Connection to 192.168.1.15 from 192.168.1.5 UA: okhttp/4.9.2 Total Clients: 7 Apr 09 00:41:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioGetState Apr 09 00:41:00 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:41:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 09 00:41:00 music-sever-luxman-dac-06 volumio[937]: info: Listing playlists Apr 09 00:41:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 09 00:41:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 09 00:41:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 09 00:41:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 09 00:41:01 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:41:01 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 563. Apr 09 00:41:01 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:41:01 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:41:01 music-sever-luxman-dac-06 go-librespot[7843]: Librespot-go daemon starting... Apr 09 00:41:01 music-sever-luxman-dac-06 go-librespot[7843]: time="2024-04-09T00:41:01+07:00" level=info msg="generated new device id: 045e29527dfdf34aa47dcdaed7e6e0665f5edd00" Apr 09 00:41:01 music-sever-luxman-dac-06 go-librespot[7843]: time="2024-04-09T00:41:01+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:41:01 music-sever-luxman-dac-06 go-librespot[7843]: time="2024-04-09T00:41:01+07:00" level=debug msg="obtained new client token: AACbQ+a5q0A3S2eD+zOW+N33jvh8SESx9/Hes2JwOfTl724wqr/0m432am1K3QqnLGikKUodiYqGn5kgKlz2szIGI2T7ifvYJgDk3Y57B6HLdSXl0ikVTAeI+64ThxkmPVYdrs67pbH5ih3G5MqO+0V8xFtdIVynLj3JxaD35vNXbiWXmsY8u7PrmvvodcIur9VqBRl6BUSLfOwJpiUXYyFKa/og7dbOEET4v5oD8d4e2dRQjfin1OI/aPrf" Apr 09 00:41:01 music-sever-luxman-dac-06 go-librespot[7843]: time="2024-04-09T00:41:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 09 00:41:01 music-sever-luxman-dac-06 go-librespot[7843]: time="2024-04-09T00:41:01+07:00" level=debug msg="completed keyexchange" Apr 09 00:41:02 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioGetQueue Apr 09 00:41:02 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::getQueue Apr 09 00:41:02 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getQueue Apr 09 00:41:02 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 09 00:41:02 music-sever-luxman-dac-06 go-librespot[7843]: time="2024-04-09T00:41:02+07:00" level=debug msg="completed challenge" Apr 09 00:41:02 music-sever-luxman-dac-06 go-librespot[7843]: time="2024-04-09T00:41:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:41:02 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:41:02 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:41:02 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:41:02 music-sever-luxman-dac-06 volumio[937]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:41:03 music-sever-luxman-dac-06 volumio[937]: error: Discovery: Generic error: TypeError: argument 8 must be an integer (port) Apr 09 00:41:03 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Started advertising with name: Music Sever Luxman Dac-06 Apr 09 00:41:05 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:41:05 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 564. Apr 09 00:41:05 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:41:05 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:41:05 music-sever-luxman-dac-06 go-librespot[7850]: Librespot-go daemon starting... Apr 09 00:41:05 music-sever-luxman-dac-06 go-librespot[7850]: time="2024-04-09T00:41:05+07:00" level=info msg="generated new device id: 598456e348ed0bc897ef8c04908bc264d23b32b3" Apr 09 00:41:05 music-sever-luxman-dac-06 go-librespot[7850]: time="2024-04-09T00:41:05+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:41:05 music-sever-luxman-dac-06 go-librespot[7850]: time="2024-04-09T00:41:05+07:00" level=debug msg="obtained new client token: AADUBeUqeshdxCHO3ICQAvnNTZT/ezUWr6MAvBxgBHx0D8NBDNCzZqcOt5D6w1qr3EliSjVcvaxYbbKNWo6PCCS/d58AI/qdWAJlk0JxF1rVgRpW3GqQ5Eu9hJIPCNMWze1MZPrW4EXM9G47vnWYrogF3ZLBTL1TYvIrMifqMKrHYAYuVCVhkUzP5AYnkjvUh9EQZUUgiDN65qIITevMJfDgnoHdOsKCalMWi1MlNxHzn1cOVIZr3Sanz4KjzY0=" Apr 09 00:41:05 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:41:05 music-sever-luxman-dac-06 go-librespot[7850]: time="2024-04-09T00:41:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 09 00:41:05 music-sever-luxman-dac-06 go-librespot[7850]: time="2024-04-09T00:41:05+07:00" level=debug msg="new websocket client" Apr 09 00:41:05 music-sever-luxman-dac-06 volumio[937]: info: Connection to go-librespot Websocket established Apr 09 00:41:05 music-sever-luxman-dac-06 go-librespot[7850]: time="2024-04-09T00:41:05+07:00" level=debug msg="completed keyexchange" Apr 09 00:41:06 music-sever-luxman-dac-06 go-librespot[7850]: time="2024-04-09T00:41:06+07:00" level=debug msg="completed challenge" Apr 09 00:41:06 music-sever-luxman-dac-06 go-librespot[7850]: time="2024-04-09T00:41:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:41:06 music-sever-luxman-dac-06 volumio[937]: info: Connection to go-librespot Websocket closed Apr 09 00:41:06 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:41:06 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: error: Discovery: Generic error: TypeError: argument 8 must be an integer (port) Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Started advertising with name: Music Sever Luxman Dac-06 Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: info: Getting Spotify volume Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: (node:937) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: (node:937) 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: 194) Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioGetState Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 09 00:41:08 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 09 00:41:09 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:41:09 music-sever-luxman-dac-06 volumio[937]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:41:09 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:41:09 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 565. Apr 09 00:41:09 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:41:09 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:41:09 music-sever-luxman-dac-06 go-librespot[7861]: Librespot-go daemon starting... Apr 09 00:41:09 music-sever-luxman-dac-06 go-librespot[7861]: time="2024-04-09T00:41:09+07:00" level=info msg="generated new device id: 93b6f9e6bb31e5a476bc7c80f8462765a7d623a2" Apr 09 00:41:09 music-sever-luxman-dac-06 go-librespot[7861]: time="2024-04-09T00:41:09+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:41:09 music-sever-luxman-dac-06 go-librespot[7861]: time="2024-04-09T00:41:09+07:00" level=debug msg="obtained new client token: AADgAGsHw6UYKwFx+4SxjVyiXKp0NT8zg1c+Auwfg/beUxydut1vhAbKZ6Zp7osTJZKSzTIaj7v1Sj3Ls67+bB/ABri2cKqsObSbpyiOZybtXFimDURlRwVzHKCs9+QWJRDJRxPHU0GDw0Rdlvn9wNfg7j2KzDnv+uz+D21LE+tYZdHmK5rDBxLXRSHTvVcCIUX6u9nQ2qvHpDN0thVnqUse2l2UitoZsDeCyuAhJ3A26l0ODjK73SOHpkAIcFA=" Apr 09 00:41:10 music-sever-luxman-dac-06 go-librespot[7861]: time="2024-04-09T00:41:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 09 00:41:10 music-sever-luxman-dac-06 go-librespot[7861]: time="2024-04-09T00:41:10+07:00" level=debug msg="completed keyexchange" Apr 09 00:41:10 music-sever-luxman-dac-06 go-librespot[7861]: time="2024-04-09T00:41:10+07:00" level=debug msg="completed challenge" Apr 09 00:41:10 music-sever-luxman-dac-06 go-librespot[7861]: time="2024-04-09T00:41:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:41:10 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:41:10 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:41:12 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:41:12 music-sever-luxman-dac-06 volumio[937]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:41:13 music-sever-luxman-dac-06 volumio[937]: error: Discovery: Generic error: TypeError: argument 8 must be an integer (port) Apr 09 00:41:13 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Started advertising with name: Music Sever Luxman Dac-06 Apr 09 00:41:14 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:41:14 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 566. Apr 09 00:41:14 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:41:14 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:41:14 music-sever-luxman-dac-06 go-librespot[7868]: Librespot-go daemon starting... Apr 09 00:41:14 music-sever-luxman-dac-06 go-librespot[7868]: time="2024-04-09T00:41:14+07:00" level=info msg="generated new device id: 75505662e4050cc80ffbe9bf268957fd29fbcb6a" Apr 09 00:41:14 music-sever-luxman-dac-06 go-librespot[7868]: time="2024-04-09T00:41:14+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:41:14 music-sever-luxman-dac-06 go-librespot[7868]: time="2024-04-09T00:41:14+07:00" level=debug msg="obtained new client token: AADE3P4yY8wa4OgPuHk0Gm0xS1tUDFNRr2QK7VYGPYEPOJqr82/hGWZqe68osiQUntF99SJhZTErFNj36Otarn5EXY9884Hb8SHN9pFBXeJCnvfKmS6zXcows9+SVVkfZIJIDj8P5tg83/hl90L3hqO+nZYpEc/YlnvBQy+g3ENvbUfTRsCQuqckA2t15LTyVducdnv+rhaUZpPsC3Gyx8/bBdVyjTh9oPkmMeAWo3lO1EaQqArFs/s1G37Rn/c=" Apr 09 00:41:14 music-sever-luxman-dac-06 go-librespot[7868]: time="2024-04-09T00:41:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 09 00:41:14 music-sever-luxman-dac-06 go-librespot[7868]: time="2024-04-09T00:41:14+07:00" level=debug msg="completed keyexchange" Apr 09 00:41:15 music-sever-luxman-dac-06 go-librespot[7868]: time="2024-04-09T00:41:15+07:00" level=debug msg="completed challenge" Apr 09 00:41:15 music-sever-luxman-dac-06 go-librespot[7868]: time="2024-04-09T00:41:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:41:15 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:41:15 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:41:15 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:41:15 music-sever-luxman-dac-06 volumio[937]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:41:18 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:41:18 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 567. Apr 09 00:41:18 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:41:18 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:41:18 music-sever-luxman-dac-06 go-librespot[7876]: Librespot-go daemon starting... Apr 09 00:41:18 music-sever-luxman-dac-06 go-librespot[7876]: time="2024-04-09T00:41:18+07:00" level=info msg="generated new device id: baf404a7582fd8cb9cc2d2e993d4a5b6be13d4b1" Apr 09 00:41:18 music-sever-luxman-dac-06 go-librespot[7876]: time="2024-04-09T00:41:18+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:41:18 music-sever-luxman-dac-06 go-librespot[7876]: time="2024-04-09T00:41:18+07:00" level=debug msg="obtained new client token: AACdrNHPQvFCXqBR4SedK8Ioy6KWxaEZed7Xldiv1O+PWA+K7cPxUSmzqgnST1zOLhkXjAO1zzmRhM+0kXs0mQZn27vpYC6vcPM2ES87J1TTUwsbv1BsugGp+w9GGswrqVMWP69MH2kxEwwnTz3Z1ZFxPHPDHmDKdjgK6gS8b5RSBqFurMQPzB8pKlqWyOAPEVZzm1bNAAGZylrfHlNkYRtGPksx7xSE+VIZsEoC/7mG88x8L29dRZKJL/i4" Apr 09 00:41:18 music-sever-luxman-dac-06 go-librespot[7876]: time="2024-04-09T00:41:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 09 00:41:18 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:41:18 music-sever-luxman-dac-06 go-librespot[7876]: time="2024-04-09T00:41:18+07:00" level=debug msg="new websocket client" Apr 09 00:41:18 music-sever-luxman-dac-06 volumio[937]: info: Connection to go-librespot Websocket established Apr 09 00:41:18 music-sever-luxman-dac-06 volumio[937]: error: Discovery: Generic error: TypeError: argument 8 must be an integer (port) Apr 09 00:41:18 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Started advertising with name: Music Sever Luxman Dac-06 Apr 09 00:41:18 music-sever-luxman-dac-06 go-librespot[7876]: time="2024-04-09T00:41:18+07:00" level=debug msg="completed keyexchange" Apr 09 00:41:19 music-sever-luxman-dac-06 go-librespot[7876]: time="2024-04-09T00:41:19+07:00" level=debug msg="completed challenge" Apr 09 00:41:19 music-sever-luxman-dac-06 go-librespot[7876]: time="2024-04-09T00:41:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:41:19 music-sever-luxman-dac-06 volumio[937]: info: Connection to go-librespot Websocket closed Apr 09 00:41:19 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:41:19 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:41:19 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 09 00:41:19 music-sever-luxman-dac-06 volumio[937]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 09 00:41:19 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 09 00:41:19 music-sever-luxman-dac-06 volumio[937]: info: Received Get System Version Apr 09 00:41:19 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 09 00:41:19 music-sever-luxman-dac-06 volumio[937]: info: Received Get System Info Apr 09 00:41:19 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 09 00:41:19 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 09 00:41:19 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Getting this device information Apr 09 00:41:19 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioGetState Apr 09 00:41:19 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:41:19 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 09 00:41:21 music-sever-luxman-dac-06 volumio[937]: info: Getting Spotify volume Apr 09 00:41:21 music-sever-luxman-dac-06 volumio[937]: (node:937) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:41:21 music-sever-luxman-dac-06 volumio[937]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Apr 09 00:41:21 music-sever-luxman-dac-06 volumio[937]: (node:937) 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: 195) Apr 09 00:41:21 music-sever-luxman-dac-06 volumio[937]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Apr 09 00:41:21 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioGetState Apr 09 00:41:21 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:41:22 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:41:22 music-sever-luxman-dac-06 volumio[937]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:41:22 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:41:22 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 568. Apr 09 00:41:22 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:41:22 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:41:22 music-sever-luxman-dac-06 go-librespot[7883]: Librespot-go daemon starting... Apr 09 00:41:22 music-sever-luxman-dac-06 go-librespot[7883]: time="2024-04-09T00:41:22+07:00" level=info msg="generated new device id: 99fe3f844fc311185c9f5e83454e24364a5f6469" Apr 09 00:41:22 music-sever-luxman-dac-06 go-librespot[7883]: time="2024-04-09T00:41:22+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:41:22 music-sever-luxman-dac-06 go-librespot[7883]: time="2024-04-09T00:41:22+07:00" level=debug msg="obtained new client token: AADjVXVcOwcVbo03BrnmCMwQ62VhldXuRRTDry9Rmj304aU2WVeol6H1EDBR+OpdqD3WWy2HPU3niO3jkKYM1jStHgTCCfwjennM3k0iVCKpgUCfuvWNbmvC6nJqai4Zrjv5asmShpNkDkzephTXzp5nox5SrdC6TSPZIYCFAyd6Xd8eAOZoTvMKtjhf0MlHwH3VjS+SdxjbIiDurFfSlZiZ1Vvi54PRW/G/jn0YRCItJWXZeMyoA/WLVnsiUqo=" Apr 09 00:41:22 music-sever-luxman-dac-06 go-librespot[7883]: time="2024-04-09T00:41:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 09 00:41:22 music-sever-luxman-dac-06 go-librespot[7883]: time="2024-04-09T00:41:22+07:00" level=debug msg="completed keyexchange" Apr 09 00:41:23 music-sever-luxman-dac-06 go-librespot[7883]: time="2024-04-09T00:41:23+07:00" level=debug msg="completed challenge" Apr 09 00:41:23 music-sever-luxman-dac-06 go-librespot[7883]: time="2024-04-09T00:41:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:41:23 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:41:23 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:41:23 music-sever-luxman-dac-06 volumio[937]: error: Discovery: Generic error: TypeError: argument 8 must be an integer (port) Apr 09 00:41:23 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Started advertising with name: Music Sever Luxman Dac-06 Apr 09 00:41:25 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:41:25 music-sever-luxman-dac-06 volumio[937]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:41:26 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:41:26 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 569. Apr 09 00:41:26 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:41:26 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:41:26 music-sever-luxman-dac-06 go-librespot[7890]: Librespot-go daemon starting... Apr 09 00:41:26 music-sever-luxman-dac-06 go-librespot[7890]: time="2024-04-09T00:41:26+07:00" level=info msg="generated new device id: feea0d534e11f58a0f7b5dcedcf973e5b7254154" Apr 09 00:41:26 music-sever-luxman-dac-06 go-librespot[7890]: time="2024-04-09T00:41:26+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:41:27 music-sever-luxman-dac-06 go-librespot[7890]: time="2024-04-09T00:41:27+07:00" level=debug msg="obtained new client token: AABiq/RsvvsFPKUa6yvhsEf53vSaukT3a0/KK5QA12vWUUPtnb6H7Px60lEQ31VoyWuHuaoa/DFmmVwdW+FoPHPfAEuhY8bwhlEQLp84RK2OZ5byg4KapSMaNgC+gnfKC3XuiLcXOjNWlhTu1eHJBND+JQB5pes3sVSlY41xWYO0jTFkQNwusDjsq1RjmcwqvbidJUtFJdp9k5Rn36RK5vimrYZLzkL3Rf5AZcQTKiMN0LVCNburMzcZ87tgvd0=" Apr 09 00:41:27 music-sever-luxman-dac-06 go-librespot[7890]: time="2024-04-09T00:41:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 09 00:41:27 music-sever-luxman-dac-06 go-librespot[7890]: time="2024-04-09T00:41:27+07:00" level=debug msg="completed keyexchange" Apr 09 00:41:27 music-sever-luxman-dac-06 go-librespot[7890]: time="2024-04-09T00:41:27+07:00" level=debug msg="completed challenge" Apr 09 00:41:27 music-sever-luxman-dac-06 go-librespot[7890]: time="2024-04-09T00:41:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:41:27 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:41:27 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:41:28 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:41:28 music-sever-luxman-dac-06 volumio[937]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:41:28 music-sever-luxman-dac-06 volumio[937]: error: Discovery: Generic error: TypeError: argument 8 must be an integer (port) Apr 09 00:41:28 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Started advertising with name: Music Sever Luxman Dac-06 Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: Found match in Cards Database: setting mixer for card Analog Out Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: Setting mixer Master for card Analog Out Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: Updating Volume Controller Parameters: Device: 0,0 Name: Analog Out Mixer: Master Max Vol: 100 Vol Curve; linear Vol Steps: 1 Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: Disabling external Volume Control Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: Preparing to generate the ALSA configuration file Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: VolumeController:: Volume=95 Mute =false Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::pushState Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioPushState Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: Asound.conf file written Apr 09 00:41:29 music-sever-luxman-dac-06 sudo[7912]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Apr 09 00:41:29 music-sever-luxman-dac-06 sudo[7912]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:41:29 music-sever-luxman-dac-06 sudo[7912]: pam_unix(sudo:session): session closed for user root Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: Found hardware: "USB-Audio" "USB Mixer" "USB1852:5065" "" "" Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: Hardware is initialized using a generic method Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: /usr/sbin/alsactl: set_control:1325: failed to obtain info for control #5 (No such file or directory) Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: Output device has changed, restarting MPD Apr 09 00:41:29 music-sever-luxman-dac-06 sudo[7917]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 09 00:41:29 music-sever-luxman-dac-06 sudo[7917]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:41:29 music-sever-luxman-dac-06 sudo[7917]: pam_unix(sudo:session): session closed for user root Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: Output device has changed, restarting Shairport Sync Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 sudo[7920]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 09 00:41:29 music-sever-luxman-dac-06 sudo[7920]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:41:29 music-sever-luxman-dac-06 systemd[1]: Stopping Music Player Daemon... Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: Output device has changed, restarting MPD Apr 09 00:41:29 music-sever-luxman-dac-06 systemd[1]: mpd.service: Succeeded. Apr 09 00:41:29 music-sever-luxman-dac-06 systemd[1]: Stopped Music Player Daemon. Apr 09 00:41:29 music-sever-luxman-dac-06 sudo[7927]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 09 00:41:29 music-sever-luxman-dac-06 sudo[7927]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:41:29 music-sever-luxman-dac-06 systemd[1]: Starting Music Player Daemon... Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: Output device has changed, restarting Shairport Sync Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 sudo[7927]: pam_unix(sudo:session): session closed for user root Apr 09 00:41:29 music-sever-luxman-dac-06 sudo[7930]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 09 00:41:29 music-sever-luxman-dac-06 sudo[7930]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:41:29 music-sever-luxman-dac-06 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 09 00:41:29 music-sever-luxman-dac-06 systemd[1]: mpd.service: Succeeded. Apr 09 00:41:29 music-sever-luxman-dac-06 systemd[1]: Stopped Music Player Daemon. Apr 09 00:41:29 music-sever-luxman-dac-06 systemd[1]: Starting Music Player Daemon... Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: MPD Permissions set Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: MPD Permissions set Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: SPOTIFY VOLUME 100 Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: VOLUMIO VOLUME 95 Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: Setting Spotify Volume from Volumio: 95 Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: Starting Shairport Sync Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: Starting Shairport Sync Apr 09 00:41:29 music-sever-luxman-dac-06 sudo[7949]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 09 00:41:29 music-sever-luxman-dac-06 sudo[7949]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:41:29 music-sever-luxman-dac-06 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 09 00:41:29 music-sever-luxman-dac-06 systemd[1]: shairport-sync.service: Succeeded. Apr 09 00:41:29 music-sever-luxman-dac-06 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 09 00:41:29 music-sever-luxman-dac-06 sudo[7952]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 09 00:41:29 music-sever-luxman-dac-06 sudo[7952]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:41:29 music-sever-luxman-dac-06 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 09 00:41:29 music-sever-luxman-dac-06 sudo[7949]: pam_unix(sudo:session): session closed for user root Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: Shairport-Sync Started Apr 09 00:41:29 music-sever-luxman-dac-06 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 09 00:41:29 music-sever-luxman-dac-06 systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Apr 09 00:41:29 music-sever-luxman-dac-06 systemd[1]: shairport-sync.service: Succeeded. Apr 09 00:41:29 music-sever-luxman-dac-06 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 09 00:41:29 music-sever-luxman-dac-06 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 09 00:41:29 music-sever-luxman-dac-06 sudo[7952]: pam_unix(sudo:session): session closed for user root Apr 09 00:41:29 music-sever-luxman-dac-06 volumio[937]: info: Shairport-Sync Started Apr 09 00:41:30 music-sever-luxman-dac-06 mpd[7933]: Apr 09 00:41 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 09 00:41:30 music-sever-luxman-dac-06 systemd[1]: Started Music Player Daemon. Apr 09 00:41:30 music-sever-luxman-dac-06 sudo[7930]: pam_unix(sudo:session): session closed for user root Apr 09 00:41:30 music-sever-luxman-dac-06 sudo[7920]: pam_unix(sudo:session): session closed for user root Apr 09 00:41:30 music-sever-luxman-dac-06 volumio[937]: error: MPD error: The expression evaluated to a falsy value: Apr 09 00:41:30 music-sever-luxman-dac-06 volumio[937]: assert.ok(self.idling) Apr 09 00:41:30 music-sever-luxman-dac-06 volumio[937]: error: The expression evaluated to a falsy value: Apr 09 00:41:30 music-sever-luxman-dac-06 volumio[937]: assert.ok(self.idling) Apr 09 00:41:30 music-sever-luxman-dac-06 volumio[937]: error: updateQueue error: null Apr 09 00:41:31 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:41:31 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 570. Apr 09 00:41:31 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:41:31 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:41:31 music-sever-luxman-dac-06 go-librespot[7960]: Librespot-go daemon starting... Apr 09 00:41:31 music-sever-luxman-dac-06 go-librespot[7960]: time="2024-04-09T00:41:31+07:00" level=info msg="generated new device id: cd6fb9fbe223e97637317a60ca37640a257a0a9d" Apr 09 00:41:31 music-sever-luxman-dac-06 go-librespot[7960]: time="2024-04-09T00:41:31+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:41:31 music-sever-luxman-dac-06 go-librespot[7960]: time="2024-04-09T00:41:31+07:00" level=debug msg="obtained new client token: AAA3pGFu7JZXjPMJKLBe/dHZbpB7TNKDjfStrgPWE/oINZ7NVQMm2bLo02AuZiqqKzrMxFIDJ0N5nvWyfckPM2OuxUifR1NdJlft2c3VZs9t2LIFDtxyEtNsXT+ydSGyOrhyqkNNL2zIT86ha2A11v0IW46NVNWs/52JwP0V0PEH1FStTzWTk7JTgzMJXU/A/qgdbmH2qA5FpIZWEanaQJkscHSdpszFu1vDIkgHdmWVnQULrUpAZG8Rnfm1XEo=" Apr 09 00:41:31 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: SETTING SPOTIFY VOLUME 95 Apr 09 00:41:31 music-sever-luxman-dac-06 volumio[937]: info: Sending Spotify command with payload to local API: /player/volume Apr 09 00:41:31 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:41:31 music-sever-luxman-dac-06 go-librespot[7960]: time="2024-04-09T00:41:31+07:00" level=debug msg="new websocket client" Apr 09 00:41:31 music-sever-luxman-dac-06 volumio[937]: info: Connection to go-librespot Websocket established Apr 09 00:41:31 music-sever-luxman-dac-06 go-librespot[7960]: time="2024-04-09T00:41:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 09 00:41:31 music-sever-luxman-dac-06 go-librespot[7960]: time="2024-04-09T00:41:31+07:00" level=debug msg="completed keyexchange" Apr 09 00:41:32 music-sever-luxman-dac-06 go-librespot[7960]: time="2024-04-09T00:41:32+07:00" level=debug msg="completed challenge" Apr 09 00:41:32 music-sever-luxman-dac-06 go-librespot[7960]: time="2024-04-09T00:41:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:41:32 music-sever-luxman-dac-06 volumio[937]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Apr 09 00:41:32 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:41:32 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:41:32 music-sever-luxman-dac-06 volumio[937]: info: Connection to go-librespot Websocket closed Apr 09 00:41:33 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Apr 09 00:41:33 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::getcurrentVolume Apr 09 00:41:33 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioRetrievevolume Apr 09 00:41:33 music-sever-luxman-dac-06 volumio[937]: info: VolumeController:: Volume=95 Mute =false Apr 09 00:41:33 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::pushState Apr 09 00:41:33 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:41:33 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioPushState Apr 09 00:41:33 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::updateTrackBlock Apr 09 00:41:33 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrackBlock Apr 09 00:41:33 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioRetrievevolume Apr 09 00:41:33 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Apr 09 00:41:33 music-sever-luxman-dac-06 volumio[937]: info: VolumeController:: Volume=95 Mute =false Apr 09 00:41:33 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::pushState Apr 09 00:41:33 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:41:33 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioPushState Apr 09 00:41:33 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Apr 09 00:41:33 music-sever-luxman-dac-06 volumio[937]: error: Discovery: Generic error: TypeError: argument 8 must be an integer (port) Apr 09 00:41:33 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Started advertising with name: Music Sever Luxman Dac-06 Apr 09 00:41:34 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:34 music-sever-luxman-dac-06 volumio[937]: info: VolumeController:: Setting startup Volume undefined Apr 09 00:41:34 music-sever-luxman-dac-06 volumio[937]: info: VolumeController::SetAlsaVolumeNaN Apr 09 00:41:34 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::pushState Apr 09 00:41:34 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:41:34 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 09 00:41:34 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioPushState Apr 09 00:41:34 music-sever-luxman-dac-06 volumio[937]: info: Getting Spotify volume Apr 09 00:41:34 music-sever-luxman-dac-06 volumio[937]: (node:937) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:41:34 music-sever-luxman-dac-06 volumio[937]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Apr 09 00:41:34 music-sever-luxman-dac-06 volumio[937]: (node:937) 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: 196) Apr 09 00:41:34 music-sever-luxman-dac-06 volumio[937]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Apr 09 00:41:34 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioGetState Apr 09 00:41:34 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:41:35 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:41:35 music-sever-luxman-dac-06 volumio[937]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:41:35 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:41:35 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 571. Apr 09 00:41:35 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:41:35 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:41:35 music-sever-luxman-dac-06 go-librespot[7972]: Librespot-go daemon starting... Apr 09 00:41:35 music-sever-luxman-dac-06 go-librespot[7972]: time="2024-04-09T00:41:35+07:00" level=info msg="generated new device id: 82fae544d77c45d1278b6234d23b43438ea495ed" Apr 09 00:41:35 music-sever-luxman-dac-06 go-librespot[7972]: time="2024-04-09T00:41:35+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:41:35 music-sever-luxman-dac-06 go-librespot[7972]: time="2024-04-09T00:41:35+07:00" level=debug msg="obtained new client token: AABZvnTfYcqZsxGpsTlucmu3KrjMZcy0jsZ2WaLDd/9KzZCk2B5iFYCwF+cNiuQR0wSNzDW8wAqNByIicq2qaJlabSRhdv5uRBsnV87mtEpKE54anpoMgRbYrfoYHT7riLeNrdWyRPfZGOizoxCRx2YTJAPf22QLzSbgTpQnxCauZoBovBjTx0IenGVd79jURYjqQfiytvpnp8Q+uxJBWxfOkUwSPmhX3/ltH+EdpqYZWxOuIhMFO1beXGeV" Apr 09 00:41:35 music-sever-luxman-dac-06 go-librespot[7972]: time="2024-04-09T00:41:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 09 00:41:35 music-sever-luxman-dac-06 go-librespot[7972]: time="2024-04-09T00:41:35+07:00" level=debug msg="completed keyexchange" Apr 09 00:41:36 music-sever-luxman-dac-06 go-librespot[7972]: time="2024-04-09T00:41:36+07:00" level=debug msg="completed challenge" Apr 09 00:41:36 music-sever-luxman-dac-06 go-librespot[7972]: time="2024-04-09T00:41:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:41:36 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:41:36 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:41:38 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:41:38 music-sever-luxman-dac-06 volumio[937]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:41:38 music-sever-luxman-dac-06 volumio[937]: error: Discovery: Generic error: TypeError: argument 8 must be an integer (port) Apr 09 00:41:38 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Started advertising with name: Music Sever Luxman Dac-06 Apr 09 00:41:39 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:41:39 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 572. Apr 09 00:41:39 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:41:39 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:41:39 music-sever-luxman-dac-06 go-librespot[7981]: Librespot-go daemon starting... Apr 09 00:41:39 music-sever-luxman-dac-06 go-librespot[7981]: time="2024-04-09T00:41:39+07:00" level=info msg="generated new device id: 5ccbba5583c043f0c2360f437f01bb62d9f3fce7" Apr 09 00:41:39 music-sever-luxman-dac-06 go-librespot[7981]: time="2024-04-09T00:41:39+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:41:39 music-sever-luxman-dac-06 go-librespot[7981]: time="2024-04-09T00:41:39+07:00" level=debug msg="obtained new client token: AACNTROjlyoP0MSyAkpaT3++xEnbnZ3QLbpi5Wp4ZxCUemtaChO1m6gCJTn82aUJxEXy8rg5sFfmlj0QW6/T9AI8Ru3GKoUykGNSCnC92RFYq9nrScmYRAEAdaqLfTRpwBfVtaiaqbQwT7zH9VqnoH1ZFtvPOiZdWopIZ5fmBg8Dk9hDispW2O8DJwfiG8tAUhWhyPFQGdYg95noETa7SRU9pDDWuJKGXWyhMka5lGRQ9YZvoSM6mDNX8kDnXOo=" Apr 09 00:41:39 music-sever-luxman-dac-06 go-librespot[7981]: time="2024-04-09T00:41:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 09 00:41:40 music-sever-luxman-dac-06 go-librespot[7981]: time="2024-04-09T00:41:40+07:00" level=debug msg="completed keyexchange" Apr 09 00:41:40 music-sever-luxman-dac-06 go-librespot[7981]: time="2024-04-09T00:41:40+07:00" level=debug msg="completed challenge" Apr 09 00:41:40 music-sever-luxman-dac-06 ntpd[6722]: Soliciting pool server 103.130.217.41 Apr 09 00:41:40 music-sever-luxman-dac-06 go-librespot[7981]: time="2024-04-09T00:41:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:41:40 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:41:40 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:41:41 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:41:41 music-sever-luxman-dac-06 volumio[937]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:41:41 music-sever-luxman-dac-06 ntpd[6722]: Soliciting pool server 103.130.217.41 Apr 09 00:41:41 music-sever-luxman-dac-06 volumiologrotate[451]: ls: cannot access '/var/log/samba/log.wb-MUSIC': No such file or directory Apr 09 00:41:41 music-sever-luxman-dac-06 volumiologrotate[451]: ls: cannot access 'SEVER': No such file or directory Apr 09 00:41:41 music-sever-luxman-dac-06 volumiologrotate[451]: ls: cannot access 'LUXMAN': No such file or directory Apr 09 00:41:41 music-sever-luxman-dac-06 volumiologrotate[451]: ls: cannot access 'DAC-06': No such file or directory Apr 09 00:41:43 music-sever-luxman-dac-06 volumio[937]: error: Discovery: Generic error: TypeError: argument 8 must be an integer (port) Apr 09 00:41:43 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Started advertising with name: Music Sever Luxman Dac-06 Apr 09 00:41:43 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:41:43 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 573. Apr 09 00:41:43 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:41:43 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:41:43 music-sever-luxman-dac-06 go-librespot[8038]: Librespot-go daemon starting... Apr 09 00:41:43 music-sever-luxman-dac-06 go-librespot[8038]: time="2024-04-09T00:41:43+07:00" level=info msg="generated new device id: 4e71925be420d5f4dff4c78f8ffd9584aec42627" Apr 09 00:41:43 music-sever-luxman-dac-06 go-librespot[8038]: time="2024-04-09T00:41:43+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:41:43 music-sever-luxman-dac-06 go-librespot[8038]: time="2024-04-09T00:41:43+07:00" level=debug msg="obtained new client token: AAANAvzphkyO568lTxuTdJO073Pu0e3WpUdhyFSwtOc5wKRdsyG0ALinsxV2JQgVk7lR/diHaqXx7pg+IUnaUTEXM1aVozSoGNfrOY/V63zQtWeyK3yJ3pA8SBItuT0U18md9suwHDBYpmGCpKAA8JA/tv3Ukf/Ekqy4FRfXUMXq89k92BkpNNFzEMSa4UjqRPdqOrYxIzzvg53LvdWNJPPo2L0v1nmajrAdJ5u/YwcVFh2uSM8sDHYPLDGo0M8=" Apr 09 00:41:44 music-sever-luxman-dac-06 go-librespot[8038]: time="2024-04-09T00:41:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 09 00:41:44 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:41:44 music-sever-luxman-dac-06 go-librespot[8038]: time="2024-04-09T00:41:44+07:00" level=debug msg="new websocket client" Apr 09 00:41:44 music-sever-luxman-dac-06 volumio[937]: info: Connection to go-librespot Websocket established Apr 09 00:41:44 music-sever-luxman-dac-06 go-librespot[8038]: time="2024-04-09T00:41:44+07:00" level=debug msg="completed keyexchange" Apr 09 00:41:44 music-sever-luxman-dac-06 go-librespot[8038]: time="2024-04-09T00:41:44+07:00" level=debug msg="completed challenge" Apr 09 00:41:44 music-sever-luxman-dac-06 go-librespot[8038]: time="2024-04-09T00:41:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:41:44 music-sever-luxman-dac-06 volumio[937]: info: Connection to go-librespot Websocket closed Apr 09 00:41:44 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:41:44 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:41:45 music-sever-luxman-dac-06 ntpd[6722]: Soliciting pool server 203.113.174.44 Apr 09 00:41:46 music-sever-luxman-dac-06 ntpd[6722]: Soliciting pool server 2406:da14:10c4:9aa0:123:: Apr 09 00:41:47 music-sever-luxman-dac-06 volumio[937]: info: Getting Spotify volume Apr 09 00:41:47 music-sever-luxman-dac-06 volumio[937]: (node:937) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:41:47 music-sever-luxman-dac-06 volumio[937]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Apr 09 00:41:47 music-sever-luxman-dac-06 volumio[937]: (node:937) 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: 197) Apr 09 00:41:47 music-sever-luxman-dac-06 volumio[937]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Apr 09 00:41:47 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioGetState Apr 09 00:41:47 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:41:47 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:41:47 music-sever-luxman-dac-06 volumio[937]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:41:48 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:41:48 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 574. Apr 09 00:41:48 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:41:48 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:41:48 music-sever-luxman-dac-06 go-librespot[8045]: Librespot-go daemon starting... Apr 09 00:41:48 music-sever-luxman-dac-06 go-librespot[8045]: time="2024-04-09T00:41:48+07:00" level=info msg="generated new device id: 1591e1aa31fb1e72efd21d3aa053f19bdaf6b09a" Apr 09 00:41:48 music-sever-luxman-dac-06 go-librespot[8045]: time="2024-04-09T00:41:48+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:41:48 music-sever-luxman-dac-06 go-librespot[8045]: time="2024-04-09T00:41:48+07:00" level=debug msg="obtained new client token: AAAeZKRTbqdvdLIFy8+g5uYVKSJwlZEx8sMNGKnDPZFj2/fs4zP/GmsbfoP4kj9kJiNi5hHvIHDvw4Y2/YZT9jR2Gqm+eGXkS5UiDyqh/UpYwGbyfjFmew1Z00TSKrSMwRyr8T/V47mLgG7xqRFkWNFZbx3rOY9/7C9zn4cdfK5N9H0Epl2V1f58wUFwKxVvvg2570na/bubNgSyvC9EmPrZEBL2ib4dhYFHMeWfpadTeudEaGrP8RJgYG5odRk=" Apr 09 00:41:48 music-sever-luxman-dac-06 go-librespot[8045]: time="2024-04-09T00:41:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 09 00:41:48 music-sever-luxman-dac-06 go-librespot[8045]: time="2024-04-09T00:41:48+07:00" level=debug msg="completed keyexchange" Apr 09 00:41:48 music-sever-luxman-dac-06 volumio[937]: error: Discovery: Generic error: TypeError: argument 8 must be an integer (port) Apr 09 00:41:48 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Started advertising with name: Music Sever Luxman Dac-06 Apr 09 00:41:48 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 09 00:41:48 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 09 00:41:48 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Getting this device information Apr 09 00:41:48 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioGetState Apr 09 00:41:48 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:41:48 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 09 00:41:48 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 09 00:41:48 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 09 00:41:48 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Getting this device information Apr 09 00:41:48 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioGetState Apr 09 00:41:48 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:41:48 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 09 00:41:49 music-sever-luxman-dac-06 go-librespot[8045]: time="2024-04-09T00:41:49+07:00" level=debug msg="completed challenge" Apr 09 00:41:49 music-sever-luxman-dac-06 go-librespot[8045]: time="2024-04-09T00:41:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:41:49 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:41:49 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:41:50 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:41:50 music-sever-luxman-dac-06 volumio[937]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:41:52 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:41:52 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 575. Apr 09 00:41:52 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:41:52 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:41:52 music-sever-luxman-dac-06 go-librespot[8054]: Librespot-go daemon starting... Apr 09 00:41:52 music-sever-luxman-dac-06 go-librespot[8054]: time="2024-04-09T00:41:52+07:00" level=info msg="generated new device id: bcfcb96b3e21253bd1eb809553e7573109a3a131" Apr 09 00:41:52 music-sever-luxman-dac-06 go-librespot[8054]: time="2024-04-09T00:41:52+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:41:52 music-sever-luxman-dac-06 go-librespot[8054]: time="2024-04-09T00:41:52+07:00" level=debug msg="obtained new client token: AADPABmRxM2fDk/ptn3o6z65kTB9+heatI9iI9sUNujIxsiC2E85Xa4VtVYelIPUg3bpFoXPZ/4DKA7Gdw96PC1xe5hYQwPJ6+qsyrkFFo0fwE6dTTKVJNlR90I3R45Hj5yK0CD6GHfL/pfuNvDXelcGKlDI7YJNmo/TBQYOXw4dlbEVuWjLVkL4TtjnRuvIE1bhVq30BlvQTYkurCrhCh45uFkXhynLJhTn34IEjNmXFG7jwGkzvJURpnZo" Apr 09 00:41:52 music-sever-luxman-dac-06 go-librespot[8054]: time="2024-04-09T00:41:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 09 00:41:52 music-sever-luxman-dac-06 go-librespot[8054]: time="2024-04-09T00:41:52+07:00" level=debug msg="completed keyexchange" Apr 09 00:41:53 music-sever-luxman-dac-06 go-librespot[8054]: time="2024-04-09T00:41:53+07:00" level=debug msg="completed challenge" Apr 09 00:41:53 music-sever-luxman-dac-06 go-librespot[8054]: time="2024-04-09T00:41:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:41:53 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:41:53 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:41:53 music-sever-luxman-dac-06 volumio[937]: error: Discovery: Generic error: TypeError: argument 8 must be an integer (port) Apr 09 00:41:53 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Started advertising with name: Music Sever Luxman Dac-06 Apr 09 00:41:53 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:41:53 music-sever-luxman-dac-06 volumio[937]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:41:54 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioPlay Apr 09 00:41:54 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::play index undefined Apr 09 00:41:54 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 09 00:41:54 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:41:55 music-sever-luxman-dac-06 volumio[937]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Apr 09 00:41:55 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Apr 09 00:41:55 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 09 00:41:55 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 09 00:41:55 music-sever-luxman-dac-06 volumio[937]: info: Setting mixer PCM for card USB D/A Converter DA-06 Apr 09 00:41:55 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 09 00:41:55 music-sever-luxman-dac-06 volumio[937]: info: Updating Volume Controller Parameters: Device: 5 Name: USB D/A Converter DA-06 Mixer: PCM Max Vol: 100 Vol Curve; linear Vol Steps: 1 Apr 09 00:41:55 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 09 00:41:55 music-sever-luxman-dac-06 volumio[937]: info: Disabling external Volume Control Apr 09 00:41:55 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 09 00:41:55 music-sever-luxman-dac-06 volumio[937]: info: Preparing to generate the ALSA configuration file Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: Asound.conf file written Apr 09 00:41:56 music-sever-luxman-dac-06 sudo[8076]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Apr 09 00:41:56 music-sever-luxman-dac-06 sudo[8076]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:41:56 music-sever-luxman-dac-06 sudo[8076]: pam_unix(sudo:session): session closed for user root Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: Found hardware: "USB-Audio" "USB Mixer" "USB1852:5065" "" "" Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: Hardware is initialized using a generic method Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: /usr/sbin/alsactl: set_control:1325: failed to obtain info for control #5 (No such file or directory) Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: Output device has changed, restarting MPD Apr 09 00:41:56 music-sever-luxman-dac-06 sudo[8081]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 09 00:41:56 music-sever-luxman-dac-06 sudo[8081]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: Output device has changed, restarting Shairport Sync Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 sudo[8081]: pam_unix(sudo:session): session closed for user root Apr 09 00:41:56 music-sever-luxman-dac-06 sudo[8084]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 09 00:41:56 music-sever-luxman-dac-06 sudo[8084]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: Stopping Music Player Daemon... Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: Output device has changed, restarting MPD Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: mpd.service: Succeeded. Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: Stopped Music Player Daemon. Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 576. Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: Output device has changed, restarting Shairport Sync Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 sudo[8090]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 09 00:41:56 music-sever-luxman-dac-06 sudo[8090]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:41:56 music-sever-luxman-dac-06 go-librespot[8091]: Librespot-go daemon starting... Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: Starting Music Player Daemon... Apr 09 00:41:56 music-sever-luxman-dac-06 sudo[8090]: pam_unix(sudo:session): session closed for user root Apr 09 00:41:56 music-sever-luxman-dac-06 go-librespot[8091]: time="2024-04-09T00:41:56+07:00" level=info msg="generated new device id: ac467d2406e08b85bd2256d3f92707d0fd377993" Apr 09 00:41:56 music-sever-luxman-dac-06 go-librespot[8091]: time="2024-04-09T00:41:56+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:41:56 music-sever-luxman-dac-06 sudo[8093]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 09 00:41:56 music-sever-luxman-dac-06 sudo[8093]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: mpd.service: Succeeded. Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: Stopped Music Player Daemon. Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: Starting Music Player Daemon... Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: MPD Permissions set Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: MPD Permissions set Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: VolumeController:: Volume=100 Mute =false Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::pushState Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioPushState Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: SPOTIFY VOLUME 95 Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: VOLUMIO VOLUME 100 Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: Setting Spotify Volume from Volumio: 100 Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: Starting Shairport Sync Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: Starting Shairport Sync Apr 09 00:41:56 music-sever-luxman-dac-06 go-librespot[8091]: time="2024-04-09T00:41:56+07:00" level=debug msg="obtained new client token: AADqJlTKRAK0pnpC/T4vahEGROEekagC32FBglEBvYw2quQpVQihOB36UcfXN18ZaFysa+EVCVjrqmBanw32nfmq+Gl6UDWb0XqOMh2VCeAcM+S/aO+cdaf5o9QgN7ZgA3RYIsu9wd40ztYqvJhXSlJYBufWBMC7udphAlGC6hPhqvumhyX85u6nros5TrTQnpi5XfoTk7TBOKc0mf1XLphTFNVvzfu8Xz3dWNhX3IuRi+kiEaVf4hWbJRWS" Apr 09 00:41:56 music-sever-luxman-dac-06 sudo[8124]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 09 00:41:56 music-sever-luxman-dac-06 sudo[8124]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:41:56 music-sever-luxman-dac-06 sudo[8122]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 09 00:41:56 music-sever-luxman-dac-06 sudo[8122]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: shairport-sync.service: Succeeded. Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 09 00:41:56 music-sever-luxman-dac-06 sudo[8124]: pam_unix(sudo:session): session closed for user root Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: Shairport-Sync Started Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: shairport-sync.service: Succeeded. Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 09 00:41:56 music-sever-luxman-dac-06 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 09 00:41:56 music-sever-luxman-dac-06 sudo[8122]: pam_unix(sudo:session): session closed for user root Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: Shairport-Sync Started Apr 09 00:41:56 music-sever-luxman-dac-06 go-librespot[8091]: time="2024-04-09T00:41:56+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:41:56 music-sever-luxman-dac-06 go-librespot[8091]: time="2024-04-09T00:41:56+07:00" level=debug msg="new websocket client" Apr 09 00:41:56 music-sever-luxman-dac-06 volumio[937]: info: Connection to go-librespot Websocket established Apr 09 00:41:56 music-sever-luxman-dac-06 go-librespot[8091]: time="2024-04-09T00:41:56+07:00" level=debug msg="completed keyexchange" Apr 09 00:41:57 music-sever-luxman-dac-06 mpd[8106]: Apr 09 00:41 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 09 00:41:57 music-sever-luxman-dac-06 systemd[1]: Started Music Player Daemon. Apr 09 00:41:57 music-sever-luxman-dac-06 sudo[8084]: pam_unix(sudo:session): session closed for user root Apr 09 00:41:57 music-sever-luxman-dac-06 sudo[8093]: pam_unix(sudo:session): session closed for user root Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: error: MPD error: The expression evaluated to a falsy value: Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: assert.ok(self.idling) Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: error: The expression evaluated to a falsy value: Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: assert.ok(self.idling) Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: error: updateQueue error: null Apr 09 00:41:57 music-sever-luxman-dac-06 go-librespot[8091]: time="2024-04-09T00:41:57+07:00" level=debug msg="completed challenge" Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: Setting mixer PCM for card USB D/A Converter DA-06 Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: Updating Volume Controller Parameters: Device: 5 Name: USB D/A Converter DA-06 Mixer: PCM Max Vol: 100 Vol Curve; linear Vol Steps: 1 Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: Disabling external Volume Control Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: Preparing to generate the ALSA configuration file Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: Asound.conf file unchanged, so no further update is needed Apr 09 00:41:57 music-sever-luxman-dac-06 volumio[937]: info: Output device has changed, restarting MPD Apr 09 00:41:58 music-sever-luxman-dac-06 sudo[8147]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 09 00:41:58 music-sever-luxman-dac-06 sudo[8147]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:41:58 music-sever-luxman-dac-06 sudo[8147]: pam_unix(sudo:session): session closed for user root Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: Output device has changed, restarting Shairport Sync Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 09 00:41:58 music-sever-luxman-dac-06 sudo[8150]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 09 00:41:58 music-sever-luxman-dac-06 sudo[8150]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:41:58 music-sever-luxman-dac-06 systemd[1]: Stopping Music Player Daemon... Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: Sending Spotify command with payload to local API: /player/volume Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: MPD Permissions set Apr 09 00:41:58 music-sever-luxman-dac-06 systemd[1]: mpd.service: Succeeded. Apr 09 00:41:58 music-sever-luxman-dac-06 systemd[1]: Stopped Music Player Daemon. Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:58 music-sever-luxman-dac-06 systemd[1]: Starting Music Player Daemon... Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: VolumeController:: Volume=100 Mute =false Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::pushState Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioPushState Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: Starting Shairport Sync Apr 09 00:41:58 music-sever-luxman-dac-06 go-librespot[8091]: time="2024-04-09T00:41:58+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:41:58 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:41:58 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: Connection to go-librespot Websocket closed Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 09 00:41:58 music-sever-luxman-dac-06 sudo[8165]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 09 00:41:58 music-sever-luxman-dac-06 sudo[8165]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:41:58 music-sever-luxman-dac-06 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 09 00:41:58 music-sever-luxman-dac-06 systemd[1]: shairport-sync.service: Succeeded. Apr 09 00:41:58 music-sever-luxman-dac-06 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 09 00:41:58 music-sever-luxman-dac-06 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 09 00:41:58 music-sever-luxman-dac-06 sudo[8165]: pam_unix(sudo:session): session closed for user root Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: Shairport-Sync Started Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: error: Discovery: Generic error: TypeError: argument 8 must be an integer (port) Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Started advertising with name: Music Sever Luxman Dac-06 Apr 09 00:41:58 music-sever-luxman-dac-06 mpd[8155]: Apr 09 00:41 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 09 00:41:58 music-sever-luxman-dac-06 systemd[1]: Started Music Player Daemon. Apr 09 00:41:58 music-sever-luxman-dac-06 sudo[8150]: pam_unix(sudo:session): session closed for user root Apr 09 00:41:58 music-sever-luxman-dac-06 volumio[937]: error: updateQueue error: null Apr 09 00:41:59 music-sever-luxman-dac-06 volumio[937]: info: Getting Spotify volume Apr 09 00:41:59 music-sever-luxman-dac-06 volumio[937]: (node:937) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:41:59 music-sever-luxman-dac-06 volumio[937]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Apr 09 00:41:59 music-sever-luxman-dac-06 volumio[937]: (node:937) 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: 198) Apr 09 00:41:59 music-sever-luxman-dac-06 volumio[937]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Apr 09 00:41:59 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioGetState Apr 09 00:41:59 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:41:59 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 09 00:41:59 music-sever-luxman-dac-06 volumio[937]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Apr 09 00:41:59 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Apr 09 00:41:59 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 09 00:41:59 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: Setting mixer PCM for card USB D/A Converter DA-06 Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: Updating Volume Controller Parameters: Device: 5 Name: USB D/A Converter DA-06 Mixer: PCM Max Vol: 100 Vol Curve; linear Vol Steps: 1 Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: Disabling external Volume Control Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: Preparing to generate the ALSA configuration file Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::getcurrentVolume Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioRetrievevolume Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: VolumeController:: Volume=100 Mute =false Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::pushState Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioPushState Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: Asound.conf file unchanged, so no further update is needed Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: Output device has changed, restarting MPD Apr 09 00:42:00 music-sever-luxman-dac-06 sudo[8189]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 09 00:42:00 music-sever-luxman-dac-06 sudo[8189]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: Output device has changed, restarting Shairport Sync Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 sudo[8189]: pam_unix(sudo:session): session closed for user root Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 sudo[8191]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 09 00:42:00 music-sever-luxman-dac-06 sudo[8191]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:42:00 music-sever-luxman-dac-06 systemd[1]: Stopping Music Player Daemon... Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 09 00:42:00 music-sever-luxman-dac-06 systemd[1]: mpd.service: Succeeded. Apr 09 00:42:00 music-sever-luxman-dac-06 systemd[1]: Stopped Music Player Daemon. Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: MPD Permissions set Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: VolumeController:: Volume=100 Mute =false Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::pushState Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioPushState Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::updateTrackBlock Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrackBlock Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioRetrievevolume Apr 09 00:42:00 music-sever-luxman-dac-06 systemd[1]: Starting Music Player Daemon... Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: Starting Shairport Sync Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: VolumeController:: Volume=100 Mute =false Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::pushState Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioPushState Apr 09 00:42:00 music-sever-luxman-dac-06 sudo[8207]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 09 00:42:00 music-sever-luxman-dac-06 sudo[8207]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:42:00 music-sever-luxman-dac-06 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 09 00:42:00 music-sever-luxman-dac-06 systemd[1]: shairport-sync.service: Succeeded. Apr 09 00:42:00 music-sever-luxman-dac-06 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 09 00:42:00 music-sever-luxman-dac-06 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 09 00:42:00 music-sever-luxman-dac-06 sudo[8207]: pam_unix(sudo:session): session closed for user root Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: info: Shairport-Sync Started Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: (node:937) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pbeg listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: (node:937) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 meta listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: (node:937) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 prgr listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: (node:937) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pvol listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Apr 09 00:42:00 music-sever-luxman-dac-06 volumio[937]: (node:937) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pend listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Apr 09 00:42:01 music-sever-luxman-dac-06 mpd[8197]: Apr 09 00:42 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 09 00:42:01 music-sever-luxman-dac-06 systemd[1]: Started Music Player Daemon. Apr 09 00:42:01 music-sever-luxman-dac-06 sudo[8191]: pam_unix(sudo:session): session closed for user root Apr 09 00:42:01 music-sever-luxman-dac-06 volumio[937]: error: updateQueue error: null Apr 09 00:42:01 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:42:01 music-sever-luxman-dac-06 volumio[937]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:42:01 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:42:01 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 577. Apr 09 00:42:01 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:42:01 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:42:01 music-sever-luxman-dac-06 go-librespot[8214]: Librespot-go daemon starting... Apr 09 00:42:01 music-sever-luxman-dac-06 go-librespot[8214]: time="2024-04-09T00:42:01+07:00" level=info msg="generated new device id: 6407fa10025713e3928d9c08ec604a842e586bb0" Apr 09 00:42:01 music-sever-luxman-dac-06 go-librespot[8214]: time="2024-04-09T00:42:01+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:42:01 music-sever-luxman-dac-06 go-librespot[8214]: time="2024-04-09T00:42:01+07:00" level=debug msg="obtained new client token: AAAib20F7GH2fYZBXjBsbFOd2WCj2azBDHUuSqpeFT4Qg1an25jMv4EIn4t/xCqe1ICM2mkKBV5WOGvN+ee9eXMd5ovLOFdxCWKotIQsqvARRLLWaauo2Tj1E1BpANc7zyJZo+FdogwKr/pSvsshPqo3VGLdWv4cR3zAT+hnbDvZVTLWWiI5d2ZeBLq40YZOekVXmSfn9hx8GMi5pKXOcJ8aVF3NW33cksDKfRwC5vh3U56eEAdi037FSXAG" Apr 09 00:42:01 music-sever-luxman-dac-06 go-librespot[8214]: time="2024-04-09T00:42:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 09 00:42:01 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Apr 09 00:42:01 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::getcurrentVolume Apr 09 00:42:01 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioRetrievevolume Apr 09 00:42:01 music-sever-luxman-dac-06 go-librespot[8214]: time="2024-04-09T00:42:01+07:00" level=debug msg="completed keyexchange" Apr 09 00:42:01 music-sever-luxman-dac-06 volumio[937]: info: VolumeController:: Volume=100 Mute =false Apr 09 00:42:01 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::pushState Apr 09 00:42:01 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:42:01 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioPushState Apr 09 00:42:01 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::updateTrackBlock Apr 09 00:42:01 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrackBlock Apr 09 00:42:01 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioRetrievevolume Apr 09 00:42:01 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 09 00:42:02 music-sever-luxman-dac-06 volumio[937]: info: VolumeController:: Volume=100 Mute =false Apr 09 00:42:02 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::pushState Apr 09 00:42:02 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:42:02 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioPushState Apr 09 00:42:02 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 09 00:42:02 music-sever-luxman-dac-06 go-librespot[8214]: time="2024-04-09T00:42:02+07:00" level=debug msg="completed challenge" Apr 09 00:42:02 music-sever-luxman-dac-06 go-librespot[8214]: time="2024-04-09T00:42:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:42:02 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:42:02 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: Retrieving Cloud Streaming UI Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: Getting Tidal Cloud Configuration Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: Getting Qobuz Cloud Configuration Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: Asking plugin for UI Config Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: Getting Spotify Cloud Configuration Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: Asking plugin for UI Config Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: Saving Spotify Acccount Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: Got Tidal Cloud Configuration Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: Got it Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: Got it Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioGetBrowseSources Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioGetBrowseSources Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioGetBrowseSources Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: error: Discovery: Generic error: TypeError: argument 8 must be an integer (port) Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Started advertising with name: Music Sever Luxman Dac-06 Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 09 00:42:03 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Apr 09 00:42:04 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Apr 09 00:42:04 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::getcurrentVolume Apr 09 00:42:04 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioRetrievevolume Apr 09 00:42:04 music-sever-luxman-dac-06 volumio[937]: info: VolumeController:: Volume=100 Mute =false Apr 09 00:42:04 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::pushState Apr 09 00:42:04 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:42:04 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioPushState Apr 09 00:42:04 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::updateTrackBlock Apr 09 00:42:04 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrackBlock Apr 09 00:42:04 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioRetrievevolume Apr 09 00:42:04 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 09 00:42:04 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:42:04 music-sever-luxman-dac-06 volumio[937]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:42:04 music-sever-luxman-dac-06 volumio[937]: info: VolumeController:: Volume=100 Mute =false Apr 09 00:42:04 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::pushState Apr 09 00:42:04 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:42:04 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioPushState Apr 09 00:42:04 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: verbose: ControllerMpd::sendMpdCommand rescan Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: verbose: ControllerMpd::sendMpdCommand status Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: ---------------------------- MPD announces state update: update Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: sendMpdCommand rescan took 2 milliseconds Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: ControllerMpd::getState Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: verbose: ControllerMpd::sendMpdCommand status Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: sendMpdCommand status took 8 milliseconds Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: sendMpdCommand status took 7 milliseconds Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: verbose: ControllerMpd::parseState Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: Command Router : Notfying DB Updatetrue Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::Close All Modals sent Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: verbose: ControllerMpd::parseState Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: ControllerMpd::pushState Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::servicePushState Apr 09 00:42:05 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::pushState Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioPushState Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: verbose: CURRENT POSITION 0 Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::syncState stateService stop Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::syncState currentStatus stop Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::pushState Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioPushState Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: No code Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: CoreStateMachine::pushState Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioPushState Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: info: ------------------------------ 47ms Apr 09 00:42:05 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 09 00:42:05 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 578. Apr 09 00:42:05 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:42:05 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:42:05 music-sever-luxman-dac-06 go-librespot[8238]: Librespot-go daemon starting... Apr 09 00:42:05 music-sever-luxman-dac-06 go-librespot[8238]: time="2024-04-09T00:42:05+07:00" level=info msg="generated new device id: 97ec8d0ff7575e0a959102fc2813161a2d5c8061" Apr 09 00:42:05 music-sever-luxman-dac-06 go-librespot[8238]: time="2024-04-09T00:42:05+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:42:05 music-sever-luxman-dac-06 go-librespot[8238]: time="2024-04-09T00:42:05+07:00" level=debug msg="obtained new client token: AAAVRjYgiWuHwE60uSVl0CWsH2qy1mXApzxRTk3Fw3yXypnJgFKz8hvV1qUBwASG5XTszQjx6vcDrpcyJC1VU+P31TqcbmQBGhUYBhKLJ4vyn1/5Vfk0PS/XOQ/Az7X1Ijgv12pODTS7Xs1EEE/ZCYfQgE1PszDcUG6CqVj+MuJ9saiRZsjX3ZGoRwEuqjmu3L52O8EBcq4kyebwgDonudWt89LXWWmsQhztAiAmdN4e7zUPnKPxjwe8hlSeLHk=" Apr 09 00:42:06 music-sever-luxman-dac-06 go-librespot[8238]: time="2024-04-09T00:42:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 09 00:42:06 music-sever-luxman-dac-06 go-librespot[8238]: time="2024-04-09T00:42:06+07:00" level=debug msg="completed keyexchange" Apr 09 00:42:06 music-sever-luxman-dac-06 go-librespot[8238]: time="2024-04-09T00:42:06+07:00" level=debug msg="completed challenge" Apr 09 00:42:06 music-sever-luxman-dac-06 go-librespot[8238]: time="2024-04-09T00:42:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:42:06 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:42:06 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:42:07 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:42:07 music-sever-luxman-dac-06 volumio[937]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:42:07 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 09 00:42:08 music-sever-luxman-dac-06 volumio[937]: error: Discovery: Generic error: TypeError: argument 8 must be an integer (port) Apr 09 00:42:08 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Started advertising with name: Music Sever Luxman Dac-06 Apr 09 00:42:10 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:42:10 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 579. Apr 09 00:42:10 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:42:10 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:42:10 music-sever-luxman-dac-06 go-librespot[8245]: Librespot-go daemon starting... Apr 09 00:42:10 music-sever-luxman-dac-06 go-librespot[8245]: time="2024-04-09T00:42:10+07:00" level=info msg="generated new device id: 75c7903a4a0a0d4ad12bbeb2af52032dc657f0bc" Apr 09 00:42:10 music-sever-luxman-dac-06 go-librespot[8245]: time="2024-04-09T00:42:10+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:42:10 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:42:10 music-sever-luxman-dac-06 go-librespot[8245]: time="2024-04-09T00:42:10+07:00" level=debug msg="new websocket client" Apr 09 00:42:10 music-sever-luxman-dac-06 volumio[937]: info: Connection to go-librespot Websocket established Apr 09 00:42:10 music-sever-luxman-dac-06 go-librespot[8245]: time="2024-04-09T00:42:10+07:00" level=debug msg="obtained new client token: AACrq5jr6X9zJfq6RIxS0+cwbkeyPp6RCeACJV9wyy5hUTn8DkQP8RZJrl7Vkau07tDOoOBGCpNzmjKsREYuK8cGuI68KjGwo6Wr5F4dIlMvY3emUpG2EGyYhWIeLzHff6FaebPkbvb1ddzo8fryLZUFAQewt7lYMDnU58k18ozQ44wmkzMQHX6wib8zWrQe9hGI8Nvs+KCQLjpTHPHwf7RJH8+zytWgXxJ6YyPX45sS0gCyJEYCCoIYZC2GSDM=" Apr 09 00:42:10 music-sever-luxman-dac-06 go-librespot[8245]: time="2024-04-09T00:42:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 09 00:42:10 music-sever-luxman-dac-06 go-librespot[8245]: time="2024-04-09T00:42:10+07:00" level=debug msg="completed keyexchange" Apr 09 00:42:10 music-sever-luxman-dac-06 go-librespot[8245]: time="2024-04-09T00:42:10+07:00" level=debug msg="completed challenge" Apr 09 00:42:11 music-sever-luxman-dac-06 go-librespot[8245]: time="2024-04-09T00:42:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:42:11 music-sever-luxman-dac-06 volumio[937]: info: Connection to go-librespot Websocket closed Apr 09 00:42:11 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:42:11 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:42:11 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 09 00:42:13 music-sever-luxman-dac-06 volumio[937]: info: Getting Spotify volume Apr 09 00:42:13 music-sever-luxman-dac-06 volumio[937]: (node:937) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:42:13 music-sever-luxman-dac-06 volumio[937]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Apr 09 00:42:13 music-sever-luxman-dac-06 volumio[937]: (node:937) 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: 199) Apr 09 00:42:13 music-sever-luxman-dac-06 volumio[937]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Apr 09 00:42:13 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::volumioGetState Apr 09 00:42:13 music-sever-luxman-dac-06 volumio[937]: info: CorePlayQueue::getTrack 0 Apr 09 00:42:13 music-sever-luxman-dac-06 volumio[937]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 09 00:42:13 music-sever-luxman-dac-06 volumio[937]: error: Discovery: Generic error: TypeError: argument 8 must be an integer (port) Apr 09 00:42:13 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Started advertising with name: Music Sever Luxman Dac-06 Apr 09 00:42:14 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:42:14 music-sever-luxman-dac-06 volumio[937]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:42:14 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:42:14 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580. Apr 09 00:42:14 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:42:14 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:42:14 music-sever-luxman-dac-06 go-librespot[8252]: Librespot-go daemon starting... Apr 09 00:42:14 music-sever-luxman-dac-06 go-librespot[8252]: time="2024-04-09T00:42:14+07:00" level=info msg="generated new device id: a1f5d28460e2272e78ae3fe4685bc6c3ed10cd98" Apr 09 00:42:14 music-sever-luxman-dac-06 go-librespot[8252]: time="2024-04-09T00:42:14+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:42:14 music-sever-luxman-dac-06 go-librespot[8252]: time="2024-04-09T00:42:14+07:00" level=debug msg="obtained new client token: AADeH4RG7p1aofvkT+qXvjscrKz7w13BL9zPJNPdVjAy8vY3WEc9rxhMcCqeo/VwnSIkLtabbLv8c9Gu2H2ckHNu3K3sRdwGzMQfDKEHulpvIJiXNLGImimpSonW5h9ThNkVET5eMeMW4vt/+eZhJ3P9whjAxLvQRtGPbGTfl+Z8hQ8cTNjxgbaZG7uwg3BTkG8ANvVZE6726l4qCKrsRRg9NXgI1604HtyRqoR2d3quaBYKMaPPifdmUkwC" Apr 09 00:42:14 music-sever-luxman-dac-06 go-librespot[8252]: time="2024-04-09T00:42:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 09 00:42:14 music-sever-luxman-dac-06 go-librespot[8252]: time="2024-04-09T00:42:14+07:00" level=debug msg="completed keyexchange" Apr 09 00:42:14 music-sever-luxman-dac-06 volumio[937]: info: Disabling MyMusic plugin upnp Apr 09 00:42:14 music-sever-luxman-dac-06 sudo[8260]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Apr 09 00:42:14 music-sever-luxman-dac-06 sudo[8260]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 09 00:42:14 music-sever-luxman-dac-06 systemd[1]: Stopping UPnP Renderer front-end to MPD... Apr 09 00:42:14 music-sever-luxman-dac-06 volumio[937]: error: Upnp client error: Error: This socket has been ended by the other party Apr 09 00:42:15 music-sever-luxman-dac-06 go-librespot[8252]: time="2024-04-09T00:42:15+07:00" level=debug msg="completed challenge" Apr 09 00:42:15 music-sever-luxman-dac-06 go-librespot[8252]: time="2024-04-09T00:42:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:42:15 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:42:15 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:42:15 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 09 00:42:17 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:42:17 music-sever-luxman-dac-06 volumio[937]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:42:18 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Apr 09 00:42:18 music-sever-luxman-dac-06 volumio[937]: verbose: ControllerMpd::sendMpdCommand rescan Apr 09 00:42:18 music-sever-luxman-dac-06 volumio[937]: info: sendMpdCommand rescan took 2 milliseconds Apr 09 00:42:18 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:42:18 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 581. Apr 09 00:42:18 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:42:18 music-sever-luxman-dac-06 go-librespot[8263]: Librespot-go daemon starting... Apr 09 00:42:18 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:42:18 music-sever-luxman-dac-06 go-librespot[8263]: time="2024-04-09T00:42:18+07:00" level=info msg="generated new device id: c60e1606b761b4e69eb2498a963a92520f9d165c" Apr 09 00:42:18 music-sever-luxman-dac-06 go-librespot[8263]: time="2024-04-09T00:42:18+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:42:18 music-sever-luxman-dac-06 volumio[937]: error: Discovery: Generic error: TypeError: argument 8 must be an integer (port) Apr 09 00:42:18 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Started advertising with name: Music Sever Luxman Dac-06 Apr 09 00:42:18 music-sever-luxman-dac-06 go-librespot[8263]: time="2024-04-09T00:42:18+07:00" level=debug msg="obtained new client token: AABUjL/QnUYpkEd5hbZp81V64uXdUGp+nh/Ifdgbh5dipIGTcIebfq+cRs+KfzgDlGsF+4SJDzMJMoQHszjTYGX96+bnpWl2k9v6VQldGARHwRPnGnuRTNCl2lGklisrI4QuIYNp63n0tG+OeNSfyhSe5kTSFV6xye2NTKTk53laNf+o3oMLS5ucVr3SCOLEXCHBeDouWx7GUnpVXeagGbYd+Z7zyeSkegGQyVuFDueATSQTxdzdSgR7Os0py00=" Apr 09 00:42:18 music-sever-luxman-dac-06 go-librespot[8263]: time="2024-04-09T00:42:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 09 00:42:18 music-sever-luxman-dac-06 go-librespot[8263]: time="2024-04-09T00:42:18+07:00" level=debug msg="completed keyexchange" Apr 09 00:42:19 music-sever-luxman-dac-06 go-librespot[8263]: time="2024-04-09T00:42:19+07:00" level=debug msg="completed challenge" Apr 09 00:42:19 music-sever-luxman-dac-06 go-librespot[8263]: time="2024-04-09T00:42:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:42:19 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:42:19 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:42:19 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 09 00:42:20 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:42:20 music-sever-luxman-dac-06 volumio[937]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 09 00:42:22 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 09 00:42:22 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 582. Apr 09 00:42:22 music-sever-luxman-dac-06 systemd[1]: Stopped go-librespot Daemon. Apr 09 00:42:22 music-sever-luxman-dac-06 systemd[1]: Started go-librespot Daemon. Apr 09 00:42:22 music-sever-luxman-dac-06 go-librespot[8270]: Librespot-go daemon starting... Apr 09 00:42:22 music-sever-luxman-dac-06 go-librespot[8270]: time="2024-04-09T00:42:22+07:00" level=info msg="generated new device id: f0da044505ef1b7146416a8bd41cb81d446a11b8" Apr 09 00:42:22 music-sever-luxman-dac-06 go-librespot[8270]: time="2024-04-09T00:42:22+07:00" level=debug msg="stored credentials found for 31ujjezbpko27oq3acmjdbuy543a" Apr 09 00:42:23 music-sever-luxman-dac-06 go-librespot[8270]: time="2024-04-09T00:42:23+07:00" level=debug msg="obtained new client token: AAALFWKzAu5CdduYa4B5Op9WPmSBZok7aMUzGLQb+Dlb8HvG+pk9Td7QUcY65ialKfV/olI65cUJlVhzWhhSEeHpoyokUYmmH9/7AtVsAWmdM73YHv4YKHVYf7ar5FtbI8hATbwTrLLdpXibeXrXYSfJQfFLCb9CFC9J0SN4lDij+BAt2FuQN8hdthsyIPNde35iFU3UWcqhJL3MY7q+IUvN5BDlWHiBiB9ejsAV12qceRiMuBxM2Dc5GewCp5Q=" Apr 09 00:42:23 music-sever-luxman-dac-06 volumio[937]: info: Initializing connection to go-librespot Websocket Apr 09 00:42:23 music-sever-luxman-dac-06 go-librespot[8270]: time="2024-04-09T00:42:23+07:00" level=debug msg="new websocket client" Apr 09 00:42:23 music-sever-luxman-dac-06 volumio[937]: info: Connection to go-librespot Websocket established Apr 09 00:42:23 music-sever-luxman-dac-06 go-librespot[8270]: time="2024-04-09T00:42:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 09 00:42:23 music-sever-luxman-dac-06 go-librespot[8270]: time="2024-04-09T00:42:23+07:00" level=debug msg="completed keyexchange" Apr 09 00:42:23 music-sever-luxman-dac-06 volumio[937]: error: Discovery: Generic error: TypeError: argument 8 must be an integer (port) Apr 09 00:42:23 music-sever-luxman-dac-06 volumio[937]: info: Discovery: Started advertising with name: Music Sever Luxman Dac-06 Apr 09 00:42:23 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 09 00:42:23 music-sever-luxman-dac-06 go-librespot[8270]: time="2024-04-09T00:42:23+07:00" level=debug msg="completed challenge" Apr 09 00:42:23 music-sever-luxman-dac-06 go-librespot[8270]: time="2024-04-09T00:42:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 09 00:42:23 music-sever-luxman-dac-06 volumio[937]: info: Connection to go-librespot Websocket closed Apr 09 00:42:23 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 09 00:42:23 music-sever-luxman-dac-06 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: info: Enabling MyMusic plugin upnp Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: info: Enabling plugin upnp Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: info: Loading plugin "upnp"... Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: info: [1712598144573] Starting Upmpd Daemon Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: Error: listen EADDRINUSE: address already in use :::6599 Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: at listenInCluster (net.js:1379:12) Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: at Server.listen (net.js:1465:7) Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: code: 'EADDRINUSE', Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: errno: -98, Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: syscall: 'listen', Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: address: '::', Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: port: 6599 Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: } Apr 09 00:42:24 music-sever-luxman-dac-06 volumio[937]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 09 00:42:24 music-sever-luxman-dac-06 sudo[8286]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-09 00:41 Apr 09 00:42:24 music-sever-luxman-dac-06 sudo[8286]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="7b9cb4a8b52fb7148a38d6ac651c1c29e09bb92c" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="b1dcc17f6d31bf91f0abd3c3fa57506d1e0d2b6b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 01 Mar 2024 08:52:33 PM CET" VOLUMIO_VERSION="3.634" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="93edfc70711724967af109c0a39fa069"