-- 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"