-- Logs begin at Sun 2025-06-01 22:25:15 CEST, end at Thu 2025-06-05 16:17:54 CEST. -- Jun 05 16:16:00 volumio go-librespot[6691]: time="2025-06-05T16:16:00+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 05 16:16:00 volumio go-librespot[6691]: time="2025-06-05T16:16:00+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 05 16:16:00 volumio go-librespot[6691]: time="2025-06-05T16:16:00+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 05 16:16:00 volumio go-librespot[6691]: time="2025-06-05T16:16:00+02:00" level=debug msg="zeroconf server listening on port 33489" Jun 05 16:16:00 volumio go-librespot[6691]: time="2025-06-05T16:16:00+02:00" level=debug msg="obtained new client token: AADjfSnkfOcj7dKDNsVZLePzCGytFWYNjKk8A7+allvaTfkwJ/U0w0XKk1dU2lxJ8Lw43VRQNzdqaMdSpN/veb9wwNyteh2NsoM5vYixLCbP5w+oyJ8sk9PA0143yH+4WZp7gCxqjfU9zJv1f/k1o2BaXBnTMgsa6jMD6OWWPQnddS7cZqxSWzYgEzCBIqkrSWVxoFlDBwOUQou233/HMFWN7Pj4v7KKOZslFhNZF75zaeK5LynOvnI=" Jun 05 16:16:00 volumio go-librespot[6691]: time="2025-06-05T16:16:00+02:00" level=debug msg="completed keyexchange" Jun 05 16:16:00 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:16:00 volumio go-librespot[6691]: time="2025-06-05T16:16:00+02:00" level=debug msg="new websocket client" Jun 05 16:16:00 volumio volumio[1039]: info: Connection to go-librespot Websocket established Jun 05 16:16:00 volumio go-librespot[6691]: time="2025-06-05T16:16:00+02:00" level=debug msg="completed challenge" Jun 05 16:16:00 volumio go-librespot[6691]: time="2025-06-05T16:16:00+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Jun 05 16:16:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:16:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:16:00 volumio volumio[1039]: info: Connection to go-librespot Websocket closed Jun 05 16:16:02 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 16:16:03 volumio volumio[1039]: info: Getting Spotify volume Jun 05 16:16:03 volumio volumio[1039]: (node:1039) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:16:03 volumio volumio[1039]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 05 16:16:03 volumio volumio[1039]: (node:1039) 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: 62) Jun 05 16:16:03 volumio volumio[1039]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jun 05 16:16:03 volumio volumio[1039]: info: CoreCommandRouter::volumioGetState Jun 05 16:16:03 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:16:03 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:16:03 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:16:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:16:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 204. Jun 05 16:16:04 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:16:04 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:16:04 volumio go-librespot[6722]: Librespot-go daemon starting... Jun 05 16:16:04 volumio systemd[1]: Starting Cleanup of Temporary Directories... Jun 05 16:16:04 volumio go-librespot[6722]: time="2025-06-05T16:16:04+02:00" level=info msg="generated new device id: 63a291f175c8a2d9dddcebe22307f2bb630169ac" Jun 05 16:16:04 volumio go-librespot[6722]: time="2025-06-05T16:16:04+02:00" level=debug msg="stored credentials not found" Jun 05 16:16:04 volumio systemd[1]: systemd-tmpfiles-clean.service: Succeeded. Jun 05 16:16:04 volumio systemd[1]: Started Cleanup of Temporary Directories. Jun 05 16:16:04 volumio go-librespot[6722]: time="2025-06-05T16:16:04+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 05 16:16:04 volumio go-librespot[6722]: time="2025-06-05T16:16:04+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 05 16:16:04 volumio go-librespot[6722]: time="2025-06-05T16:16:04+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 05 16:16:04 volumio go-librespot[6722]: time="2025-06-05T16:16:04+02:00" level=debug msg="zeroconf server listening on port 38393" Jun 05 16:16:04 volumio go-librespot[6722]: time="2025-06-05T16:16:04+02:00" level=debug msg="obtained new client token: AADLiV3BO5244cqBLRBa69aavxes07VFfV1OlYmA4mZ8eBxp4UjjO95r1X8fus3sn5awk64eSGVj86ZJss9MTwnpmFkiGg1dcjbexAFoeqr4MKKtgNuFcgotSaZrnMtc7bJ0FK5Wn5QNiiAbjpvzdhdaeOG5BAkcAuiYoiEdPxmKj/LEJMmFZl4PoRWqAfyJeMrIrQA1ysD62f6PbQRo0Z9k9kFWZjlbEL3HkglMVn17e057TP5whLK5YA==" Jun 05 16:16:04 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 05 16:16:04 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 05 16:16:04 volumio volumio[1039]: info: Discovery: Getting this device information Jun 05 16:16:04 volumio volumio[1039]: info: CoreCommandRouter::volumioGetState Jun 05 16:16:04 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 05 16:16:04 volumio go-librespot[6722]: time="2025-06-05T16:16:04+02:00" level=debug msg="completed keyexchange" Jun 05 16:16:05 volumio go-librespot[6722]: time="2025-06-05T16:16:05+02:00" level=debug msg="completed challenge" Jun 05 16:16:05 volumio go-librespot[6722]: time="2025-06-05T16:16:05+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Jun 05 16:16:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:16:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:16:05 volumio ntpd[810]: 178.215.228.24 local addr 192.168.1.145 -> Jun 05 16:16:06 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 16:16:06 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:16:06 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:16:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:16:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 205. Jun 05 16:16:08 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:16:08 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:16:08 volumio go-librespot[6739]: Librespot-go daemon starting... Jun 05 16:16:08 volumio go-librespot[6739]: time="2025-06-05T16:16:08+02:00" level=info msg="generated new device id: c3a9eb26a2c817580c1cb84be37c401f3b7ef013" Jun 05 16:16:08 volumio go-librespot[6739]: time="2025-06-05T16:16:08+02:00" level=debug msg="stored credentials not found" Jun 05 16:16:08 volumio go-librespot[6739]: time="2025-06-05T16:16:08+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 05 16:16:08 volumio go-librespot[6739]: time="2025-06-05T16:16:08+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 05 16:16:08 volumio go-librespot[6739]: time="2025-06-05T16:16:08+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 05 16:16:08 volumio go-librespot[6739]: time="2025-06-05T16:16:08+02:00" level=debug msg="zeroconf server listening on port 37455" Jun 05 16:16:08 volumio go-librespot[6739]: time="2025-06-05T16:16:08+02:00" level=debug msg="obtained new client token: AAAHpOxbuY2xkpT82RS7D0Owp4F3OmX97mC3CFZQp6tUiZ5AaHVelBJsH0inpSHBTCtm1Mjm+NwwerNjJk4tWMC7vBs9Jb+Cj3Uwus5wv6hsHMbdAxCLYkEuE7WBjlTrvmMVVneocLVN9bonD0bPqgIefbwoLaMJfJVBAoRCPDRBIsYjifunK5HSaQKZYtdKBHFo+VqrXspnx6Rd6R2MyZ6EB71f0mZZJt8vn5a/QBRi2PhsEov9WJcAUQ==" Jun 05 16:16:08 volumio go-librespot[6739]: time="2025-06-05T16:16:08+02:00" level=debug msg="completed keyexchange" Jun 05 16:16:09 volumio go-librespot[6739]: time="2025-06-05T16:16:09+02:00" level=debug msg="completed challenge" Jun 05 16:16:09 volumio go-librespot[6739]: time="2025-06-05T16:16:09+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Jun 05 16:16:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:16:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:16:09 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:16:09 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:16:10 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 16:16:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:16:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 206. Jun 05 16:16:12 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:16:12 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:16:12 volumio go-librespot[6772]: Librespot-go daemon starting... Jun 05 16:16:12 volumio go-librespot[6772]: time="2025-06-05T16:16:12+02:00" level=info msg="generated new device id: da9365b3fc631779e4dfd5af7a8f26fa25550c2d" Jun 05 16:16:12 volumio go-librespot[6772]: time="2025-06-05T16:16:12+02:00" level=debug msg="stored credentials not found" Jun 05 16:16:12 volumio go-librespot[6772]: time="2025-06-05T16:16:12+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 05 16:16:12 volumio go-librespot[6772]: time="2025-06-05T16:16:12+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 05 16:16:12 volumio go-librespot[6772]: time="2025-06-05T16:16:12+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 05 16:16:12 volumio go-librespot[6772]: time="2025-06-05T16:16:12+02:00" level=debug msg="zeroconf server listening on port 35307" Jun 05 16:16:12 volumio go-librespot[6772]: time="2025-06-05T16:16:12+02:00" level=debug msg="obtained new client token: AAC5+XzPbdMXkxWotnCYB9jx5y//vGJCMeZgpd62XYyUWsV5+Y+3TY5cgzEZhHGONlXoDbANijnpIJePR2qppIfZCb3rxCfw9wYxWN5qwWGDWmQV/bfPxDvju59/yW+6fllBr+Mj7VL+Dhp0aR7VvfBxwDBPoEvZex8VRJ5gTAl1lbKw8TKct0fFIfCPT4e9hNHlrc6EchWRlVfbCRO5oNWYdITN50sSPUQYoV2fiwdAVatnp7v8n3pmzg==" Jun 05 16:16:12 volumio go-librespot[6772]: time="2025-06-05T16:16:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.65.9:4070: connect: connection refused" Jun 05 16:16:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:16:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:16:12 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:16:12 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:16:14 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 16:16:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:16:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 207. Jun 05 16:16:15 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:16:15 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:16:15 volumio go-librespot[6788]: Librespot-go daemon starting... Jun 05 16:16:15 volumio go-librespot[6788]: time="2025-06-05T16:16:15+02:00" level=info msg="generated new device id: 6a1d3252c1931a2c4e8985afb84500ea19cc7ccf" Jun 05 16:16:15 volumio go-librespot[6788]: time="2025-06-05T16:16:15+02:00" level=debug msg="stored credentials not found" Jun 05 16:16:15 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:16:15 volumio go-librespot[6788]: time="2025-06-05T16:16:15+02:00" level=debug msg="new websocket client" Jun 05 16:16:15 volumio volumio[1039]: info: Connection to go-librespot Websocket established Jun 05 16:16:16 volumio go-librespot[6788]: time="2025-06-05T16:16:16+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 05 16:16:16 volumio go-librespot[6788]: time="2025-06-05T16:16:16+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 05 16:16:16 volumio go-librespot[6788]: time="2025-06-05T16:16:16+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 05 16:16:16 volumio go-librespot[6788]: time="2025-06-05T16:16:16+02:00" level=debug msg="zeroconf server listening on port 44191" Jun 05 16:16:16 volumio go-librespot[6788]: time="2025-06-05T16:16:16+02:00" level=debug msg="obtained new client token: AAAdaU6a49O2AcMfsPN0atT+4TH4Y2GsZLheT0NMsVfuZbITUdhdP1zbGy3y30x0HiyK3g9WTRb8TbTw4BiqCe1OBqCw+8jUbHIhItsfX08Itvis+sWurAJTiAqhav/1PSJUEuxtdZily1sjZ3JVIMsbvE8kTd8HLPO5tmnBnggbydcwZQZbIlh2vtOq8pF3gge4veROcCSJEkBoMLB6RC2lveUjjpUrB+EohhU7JM5NPYbDGPqMvWs=" Jun 05 16:16:16 volumio go-librespot[6788]: time="2025-06-05T16:16:16+02:00" level=debug msg="completed keyexchange" Jun 05 16:16:16 volumio go-librespot[6788]: time="2025-06-05T16:16:16+02:00" level=debug msg="completed challenge" Jun 05 16:16:16 volumio go-librespot[6788]: time="2025-06-05T16:16:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Jun 05 16:16:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:16:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:16:16 volumio volumio[1039]: info: Connection to go-librespot Websocket closed Jun 05 16:16:18 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 16:16:18 volumio volumio[1039]: info: Getting Spotify volume Jun 05 16:16:18 volumio volumio[1039]: (node:1039) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:16:18 volumio volumio[1039]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 05 16:16:18 volumio volumio[1039]: (node:1039) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 63) Jun 05 16:16:18 volumio volumio[1039]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jun 05 16:16:18 volumio volumio[1039]: info: CoreCommandRouter::volumioGetState Jun 05 16:16:18 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:16:19 volumio ntpd[810]: 217.71.200.210 local addr 192.168.1.145 -> Jun 05 16:16:19 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:16:19 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:16:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:16:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 208. Jun 05 16:16:20 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:16:20 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:16:20 volumio go-librespot[6821]: Librespot-go daemon starting... Jun 05 16:16:20 volumio go-librespot[6821]: time="2025-06-05T16:16:20+02:00" level=info msg="generated new device id: 8b6083789f998915afab29ab76f92dd5e7ab81a4" Jun 05 16:16:20 volumio go-librespot[6821]: time="2025-06-05T16:16:20+02:00" level=debug msg="stored credentials not found" Jun 05 16:16:20 volumio go-librespot[6821]: time="2025-06-05T16:16:20+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 05 16:16:20 volumio go-librespot[6821]: time="2025-06-05T16:16:20+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 05 16:16:20 volumio go-librespot[6821]: time="2025-06-05T16:16:20+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 05 16:16:20 volumio go-librespot[6821]: time="2025-06-05T16:16:20+02:00" level=debug msg="zeroconf server listening on port 44147" Jun 05 16:16:20 volumio go-librespot[6821]: time="2025-06-05T16:16:20+02:00" level=debug msg="obtained new client token: AABcRymPUGWhIlB14LJMbBdB/JAhgoXKl5dIywQurmPE0vKZasU6g37fxnPY40Pt/lZX34b9iPmFssOURlNELAVdv/QMGNEshLYu8DVPq3/to+AC2Syaylt2Io3iP83gBdTph/nzuGXil/nDaBrfv1qk6LoFRH83/ZQLEDT2vr/ZlBmROhCWzt4nTkh1tveNyQdF+gRGg68gqC8YNpB1FC9MewtS/r4ivUp1Wc3nFFgPOAXebPlDJNnB6g==" Jun 05 16:16:20 volumio go-librespot[6821]: time="2025-06-05T16:16:20+02:00" level=debug msg="completed keyexchange" Jun 05 16:16:20 volumio go-librespot[6821]: time="2025-06-05T16:16:20+02:00" level=debug msg="completed challenge" Jun 05 16:16:21 volumio go-librespot[6821]: time="2025-06-05T16:16:21+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Jun 05 16:16:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:16:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:16:22 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 16:16:22 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:16:22 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:16:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:16:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 209. Jun 05 16:16:24 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:16:24 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:16:24 volumio go-librespot[6838]: Librespot-go daemon starting... Jun 05 16:16:24 volumio go-librespot[6838]: time="2025-06-05T16:16:24+02:00" level=info msg="generated new device id: f937f0b4a24113f76ecf0ae39190b888f18f3c73" Jun 05 16:16:24 volumio go-librespot[6838]: time="2025-06-05T16:16:24+02:00" level=debug msg="stored credentials not found" Jun 05 16:16:24 volumio go-librespot[6838]: time="2025-06-05T16:16:24+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 05 16:16:24 volumio go-librespot[6838]: time="2025-06-05T16:16:24+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 05 16:16:24 volumio go-librespot[6838]: time="2025-06-05T16:16:24+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 05 16:16:24 volumio go-librespot[6838]: time="2025-06-05T16:16:24+02:00" level=debug msg="zeroconf server listening on port 33729" Jun 05 16:16:24 volumio go-librespot[6838]: time="2025-06-05T16:16:24+02:00" level=debug msg="obtained new client token: AABaWGKYSN4SDcbf3Hyv2ODK9DLQbGjzBrgq08iTWobC0Biq36IPTtpRgr9U7Op5gzkmvuAVVrVIK4+yssSr3kkxpD7Sot3gjWT6P3TQb2pdmLfTwqKB4V2JDrW0p/X+P+DT/3s3n+Z5Ex9aROqp+OgSLlI27c6Pef6MZCcwd3WjVWHotzxgeItzxaT2S2kcvMIkHGOsRtoFRj+laEUrACwgyUzJoxxGCqi+I+LMsLas2mZAqvKY0dYaIQ==" Jun 05 16:16:24 volumio go-librespot[6838]: time="2025-06-05T16:16:24+02:00" level=debug msg="completed keyexchange" Jun 05 16:16:25 volumio go-librespot[6838]: time="2025-06-05T16:16:25+02:00" level=debug msg="completed challenge" Jun 05 16:16:25 volumio go-librespot[6838]: time="2025-06-05T16:16:25+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Jun 05 16:16:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:16:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:16:25 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:16:25 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:16:26 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 16:16:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:16:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 210. Jun 05 16:16:28 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:16:28 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:16:28 volumio go-librespot[6895]: Librespot-go daemon starting... Jun 05 16:16:28 volumio go-librespot[6895]: time="2025-06-05T16:16:28+02:00" level=info msg="generated new device id: 7f5cfaf575bbf22c5b240356120c6ca946e44369" Jun 05 16:16:28 volumio go-librespot[6895]: time="2025-06-05T16:16:28+02:00" level=debug msg="stored credentials not found" Jun 05 16:16:28 volumio go-librespot[6895]: time="2025-06-05T16:16:28+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 05 16:16:28 volumio go-librespot[6895]: time="2025-06-05T16:16:28+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 05 16:16:28 volumio go-librespot[6895]: time="2025-06-05T16:16:28+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 05 16:16:28 volumio go-librespot[6895]: time="2025-06-05T16:16:28+02:00" level=debug msg="zeroconf server listening on port 42659" Jun 05 16:16:28 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:16:28 volumio volumio[1039]: info: Connection to go-librespot Websocket established Jun 05 16:16:28 volumio go-librespot[6895]: time="2025-06-05T16:16:28+02:00" level=debug msg="new websocket client" Jun 05 16:16:28 volumio go-librespot[6895]: time="2025-06-05T16:16:28+02:00" level=debug msg="obtained new client token: AACyME4dqFR0BEThRH+nS53yRPfjAYwt6hzQ5Ano0yvxycnn71Do8KBVJzQTdNoCVyPdke/gd75gbNLFT3x+kn26jYYS8u/oHIOViDdJ5z47mDEpQS5tMg2bVhXaDi3kmO072dq8oVh++5oIiUn9N1EbVFhVaKBg028AYZdPrA44/CyqVnoRgLkEGojkJN4vcgZE7nSXM2xkp1IoFLjw1R8mNxfIEbIHmb2psjJSeQf2tdlyuRhRTgmC6Q==" Jun 05 16:16:28 volumio go-librespot[6895]: time="2025-06-05T16:16:28+02:00" level=debug msg="completed keyexchange" Jun 05 16:16:29 volumio go-librespot[6895]: time="2025-06-05T16:16:29+02:00" level=debug msg="completed challenge" Jun 05 16:16:29 volumio go-librespot[6895]: time="2025-06-05T16:16:29+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Jun 05 16:16:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:16:29 volumio volumio[1039]: info: Connection to go-librespot Websocket closed Jun 05 16:16:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:16:30 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 16:16:31 volumio volumio[1039]: info: Getting Spotify volume Jun 05 16:16:31 volumio volumio[1039]: (node:1039) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:16:31 volumio volumio[1039]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 05 16:16:31 volumio volumio[1039]: (node:1039) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 64) Jun 05 16:16:31 volumio volumio[1039]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jun 05 16:16:31 volumio volumio[1039]: info: CoreCommandRouter::volumioGetState Jun 05 16:16:31 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:16:32 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:16:32 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:16:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:16:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 211. Jun 05 16:16:32 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:16:32 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:16:32 volumio go-librespot[6927]: Librespot-go daemon starting... Jun 05 16:16:32 volumio go-librespot[6927]: time="2025-06-05T16:16:32+02:00" level=info msg="generated new device id: c2cc281e6439159b9bc760e4d4d792d495d3a8c1" Jun 05 16:16:32 volumio go-librespot[6927]: time="2025-06-05T16:16:32+02:00" level=debug msg="stored credentials not found" Jun 05 16:16:33 volumio go-librespot[6927]: time="2025-06-05T16:16:33+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 05 16:16:33 volumio go-librespot[6927]: time="2025-06-05T16:16:33+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 05 16:16:33 volumio go-librespot[6927]: time="2025-06-05T16:16:33+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 05 16:16:33 volumio go-librespot[6927]: time="2025-06-05T16:16:33+02:00" level=debug msg="zeroconf server listening on port 42569" Jun 05 16:16:33 volumio go-librespot[6927]: time="2025-06-05T16:16:33+02:00" level=debug msg="obtained new client token: AAA9B7XBJYFdRw36fpJEozKi275kzB+U/rxSNimzY+b6pmyW96cxsQnywLGzqLw0r5VhQBz58ivekw8QhKZLweSfRa/2WoV1X5TSq79N4xgGatmwBAzjRethDwhGrKBl0btI+LbMjilv0nBu5axTmfoy2MnYiZjPL6vduebUnPiS1bDL/DVyYZGR7jW6KUpSkEXJDH2tEqG4A0c7WLrVdHWtny8EVRfXdKMvlDVq4C8HsKuNk7fBic0=" Jun 05 16:16:33 volumio go-librespot[6927]: time="2025-06-05T16:16:33+02:00" level=debug msg="completed keyexchange" Jun 05 16:16:33 volumio go-librespot[6927]: time="2025-06-05T16:16:33+02:00" level=debug msg="completed challenge" Jun 05 16:16:33 volumio go-librespot[6927]: time="2025-06-05T16:16:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Jun 05 16:16:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:16:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:16:34 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 16:16:34 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 05 16:16:34 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 05 16:16:34 volumio volumio[1039]: info: Discovery: Getting this device information Jun 05 16:16:34 volumio volumio[1039]: info: CoreCommandRouter::volumioGetState Jun 05 16:16:34 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 05 16:16:35 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:16:35 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:16:37 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:16:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 212. Jun 05 16:16:37 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:16:37 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:16:37 volumio go-librespot[6944]: Librespot-go daemon starting... Jun 05 16:16:37 volumio go-librespot[6944]: time="2025-06-05T16:16:37+02:00" level=info msg="generated new device id: 89ac29dcc09afd8618479c9efe3c4f5846fcfdc5" Jun 05 16:16:37 volumio go-librespot[6944]: time="2025-06-05T16:16:37+02:00" level=debug msg="stored credentials not found" Jun 05 16:16:37 volumio go-librespot[6944]: time="2025-06-05T16:16:37+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 05 16:16:37 volumio go-librespot[6944]: time="2025-06-05T16:16:37+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 05 16:16:37 volumio go-librespot[6944]: time="2025-06-05T16:16:37+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 05 16:16:37 volumio go-librespot[6944]: time="2025-06-05T16:16:37+02:00" level=debug msg="zeroconf server listening on port 43859" Jun 05 16:16:37 volumio go-librespot[6944]: time="2025-06-05T16:16:37+02:00" level=debug msg="obtained new client token: AABpne+mVmv5PfwN/PXjrRXqfms81je43weLIvdgVrPaixpGv8bqgdOQwFdcbeMMMo7YXhRzB7vGDBQ4XEsYGyNNMs3w9D+GBXicRKbA6DszESVbq1QKIhzMSIpoZaMaJcvu3cR3nvLPu2l5iwA7r+fGno+3EIJ5zeRBzz14gUtU5h4ucM8Sxv0UYfZxacCGkeKxd5MBoo/VNcIZcb+74lfgGQf6lyuSa7iic+J04nQtEHxNhM04PVANJw==" Jun 05 16:16:37 volumio go-librespot[6944]: time="2025-06-05T16:16:37+02:00" level=debug msg="completed keyexchange" Jun 05 16:16:37 volumio go-librespot[6944]: time="2025-06-05T16:16:37+02:00" level=debug msg="completed challenge" Jun 05 16:16:38 volumio go-librespot[6944]: time="2025-06-05T16:16:38+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Jun 05 16:16:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:16:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:16:38 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 16:16:38 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:16:38 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:16:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:16:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 213. Jun 05 16:16:41 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:16:41 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:16:41 volumio go-librespot[6977]: Librespot-go daemon starting... Jun 05 16:16:41 volumio go-librespot[6977]: time="2025-06-05T16:16:41+02:00" level=info msg="generated new device id: 6db090b4b78127215539d14b6a1524a05729e178" Jun 05 16:16:41 volumio go-librespot[6977]: time="2025-06-05T16:16:41+02:00" level=debug msg="stored credentials not found" Jun 05 16:16:41 volumio go-librespot[6977]: time="2025-06-05T16:16:41+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 05 16:16:41 volumio go-librespot[6977]: time="2025-06-05T16:16:41+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 05 16:16:41 volumio go-librespot[6977]: time="2025-06-05T16:16:41+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 05 16:16:41 volumio go-librespot[6977]: time="2025-06-05T16:16:41+02:00" level=debug msg="zeroconf server listening on port 43171" Jun 05 16:16:41 volumio go-librespot[6977]: time="2025-06-05T16:16:41+02:00" level=debug msg="obtained new client token: AABCN/xKF1UM86gkjwlZ7iQ7CWJsM6dUqJ684Iv44hxXTX6qTVCCNU081C7J0qdVEb1DFZjeQoMr8rymQA1QRZJvsLMR+9ZCryRUy3Mqp8dgUMw18EyuXDT/pqu/BxFDNjPgFsQbHrGtQyg7Gwz5SgEYb5NUkSA5Wu8EJyidkJ7jEyMMIryRNqvHLYioh09z82xZmAhuGbR5miI/hkyx5xINI6np/yJ9CKmOhtBldkO9JX+UrdfhNhsqCQ==" Jun 05 16:16:41 volumio go-librespot[6977]: time="2025-06-05T16:16:41+02:00" level=debug msg="completed keyexchange" Jun 05 16:16:41 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:16:41 volumio go-librespot[6977]: time="2025-06-05T16:16:41+02:00" level=debug msg="new websocket client" Jun 05 16:16:41 volumio volumio[1039]: info: Connection to go-librespot Websocket established Jun 05 16:16:41 volumio go-librespot[6977]: time="2025-06-05T16:16:41+02:00" level=debug msg="completed challenge" Jun 05 16:16:42 volumio go-librespot[6977]: time="2025-06-05T16:16:42+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Jun 05 16:16:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:16:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:16:42 volumio volumio[1039]: info: Connection to go-librespot Websocket closed Jun 05 16:16:42 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 16:16:44 volumio volumio[1039]: info: Getting Spotify volume Jun 05 16:16:44 volumio volumio[1039]: (node:1039) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:16:44 volumio volumio[1039]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 05 16:16:44 volumio volumio[1039]: (node:1039) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 65) Jun 05 16:16:44 volumio volumio[1039]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jun 05 16:16:44 volumio volumio[1039]: info: CoreCommandRouter::volumioGetState Jun 05 16:16:44 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:16:45 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:16:45 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:16:45 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:16:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 214. Jun 05 16:16:45 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:16:45 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:16:45 volumio go-librespot[6995]: Librespot-go daemon starting... Jun 05 16:16:45 volumio go-librespot[6995]: time="2025-06-05T16:16:45+02:00" level=info msg="generated new device id: 5a68b1d66f3e120f371d027d05d8b09f43c3bdea" Jun 05 16:16:45 volumio go-librespot[6995]: time="2025-06-05T16:16:45+02:00" level=debug msg="stored credentials not found" Jun 05 16:16:45 volumio go-librespot[6995]: time="2025-06-05T16:16:45+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 05 16:16:45 volumio go-librespot[6995]: time="2025-06-05T16:16:45+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 05 16:16:45 volumio go-librespot[6995]: time="2025-06-05T16:16:45+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 05 16:16:45 volumio go-librespot[6995]: time="2025-06-05T16:16:45+02:00" level=debug msg="zeroconf server listening on port 37277" Jun 05 16:16:45 volumio go-librespot[6995]: time="2025-06-05T16:16:45+02:00" level=debug msg="obtained new client token: AAC9KNEFjW8dxsnSFUJw4tkxhme5nEsrkjMZURMWPSh7KxFkcAFrvOQX0Td4Gx677qriip+DHaWVXpisLSI6JDtxlQX0gGI0m/UnCOeecdCPTAgoeGKSUCtWARQQUjwga8/iz4ROLyaE8LxZlM+X6dyO327G+YaXS6p67yUaLpMxiNGA/DB/D8WDo95Lui3FHVN9o7TTaEhI1LxM8if4qJmBBP+4/2rieh8OhWWbG+Pk/a/DJQ8ZEpDIyg==" Jun 05 16:16:45 volumio go-librespot[6995]: time="2025-06-05T16:16:45+02:00" level=debug msg="completed keyexchange" Jun 05 16:16:46 volumio go-librespot[6995]: time="2025-06-05T16:16:46+02:00" level=debug msg="completed challenge" Jun 05 16:16:46 volumio go-librespot[6995]: time="2025-06-05T16:16:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Jun 05 16:16:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:16:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:16:46 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 16:16:48 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:16:48 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:16:49 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:16:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 215. Jun 05 16:16:49 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:16:49 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:16:49 volumio go-librespot[7019]: Librespot-go daemon starting... Jun 05 16:16:49 volumio go-librespot[7019]: time="2025-06-05T16:16:49+02:00" level=info msg="generated new device id: d0e790e0cea11f18647af5d5c74ed1473e1cc375" Jun 05 16:16:49 volumio go-librespot[7019]: time="2025-06-05T16:16:49+02:00" level=debug msg="stored credentials not found" Jun 05 16:16:49 volumio go-librespot[7019]: time="2025-06-05T16:16:49+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 05 16:16:49 volumio go-librespot[7019]: time="2025-06-05T16:16:49+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 05 16:16:49 volumio go-librespot[7019]: time="2025-06-05T16:16:49+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 05 16:16:49 volumio go-librespot[7019]: time="2025-06-05T16:16:49+02:00" level=debug msg="zeroconf server listening on port 44587" Jun 05 16:16:49 volumio go-librespot[7019]: time="2025-06-05T16:16:49+02:00" level=debug msg="obtained new client token: AACuAl8xfjZP0/vpqUaENEHqzqsbaEXVrE5Bx4sQuhA8AgdaEIJkR6zr7LWqmLW+b0gKDt4OuAdeiMUK4pW5CCuIa8F9Qf0HmWS1bKg3GebEoND9s6310NTsbfOzTD0E+oC1D0Wmfa4CB+op6Ru7raM3eRVT4+Y4DpjUS/lCE0vBbGGdYh6RHEkflg3+8sDYoYlaf6XrquyEbJoz+UY1KCqhJCCWGWi/q+FlshP8BypCQccfv3bUL039ig==" Jun 05 16:16:50 volumio go-librespot[7019]: time="2025-06-05T16:16:50+02:00" level=debug msg="completed keyexchange" Jun 05 16:16:50 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 16:16:50 volumio go-librespot[7019]: time="2025-06-05T16:16:50+02:00" level=debug msg="completed challenge" Jun 05 16:16:50 volumio go-librespot[7019]: time="2025-06-05T16:16:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Jun 05 16:16:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:16:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:16:51 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:16:51 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:16:51 volumio volumio[1039]: info: MPD Database updated - AlbumList cache refreshed Jun 05 16:16:51 volumio volumio[1039]: info: Jun 05 16:16:51 volumio volumio[1039]: ---------------------------- MPD announces state update: database Jun 05 16:16:51 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:16:51 volumio volumio[1039]: info: Jun 05 16:16:51 volumio volumio[1039]: ---------------------------- MPD announces state update: update Jun 05 16:16:51 volumio volumio[1039]: info: ControllerMpd::getState Jun 05 16:16:51 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:16:51 volumio volumio[1039]: info: ControllerMpd::getState Jun 05 16:16:51 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:16:51 volumio volumio[1039]: info: MPD Database updated - AlbumList cache refreshed Jun 05 16:16:51 volumio volumio[1039]: info: Jun 05 16:16:51 volumio volumio[1039]: ---------------------------- MPD announces state update: database Jun 05 16:16:51 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:16:51 volumio volumio[1039]: info: Jun 05 16:16:51 volumio volumio[1039]: ---------------------------- MPD announces state update: update Jun 05 16:16:51 volumio volumio[1039]: info: ControllerMpd::getState Jun 05 16:16:51 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:16:51 volumio volumio[1039]: info: ControllerMpd::getState Jun 05 16:16:51 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:16:51 volumio volumio[1039]: info: MPD Database updated - AlbumList cache refreshed Jun 05 16:16:51 volumio volumio[1039]: info: Jun 05 16:16:51 volumio volumio[1039]: ---------------------------- MPD announces state update: database Jun 05 16:16:51 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:16:51 volumio volumio[1039]: info: Jun 05 16:16:51 volumio volumio[1039]: ---------------------------- MPD announces state update: update Jun 05 16:16:51 volumio volumio[1039]: info: ControllerMpd::getState Jun 05 16:16:51 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:16:51 volumio volumio[1039]: info: ControllerMpd::getState Jun 05 16:16:51 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:16:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:16:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 216. Jun 05 16:16:53 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:16:53 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:16:53 volumio go-librespot[7047]: Librespot-go daemon starting... Jun 05 16:16:53 volumio go-librespot[7047]: time="2025-06-05T16:16:53+02:00" level=info msg="generated new device id: f7153bea431e745d031b44a02eb7e2714e38063e" Jun 05 16:16:53 volumio go-librespot[7047]: time="2025-06-05T16:16:53+02:00" level=debug msg="stored credentials not found" Jun 05 16:16:54 volumio go-librespot[7047]: time="2025-06-05T16:16:54+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 05 16:16:54 volumio go-librespot[7047]: time="2025-06-05T16:16:54+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 05 16:16:54 volumio go-librespot[7047]: time="2025-06-05T16:16:54+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 05 16:16:54 volumio go-librespot[7047]: time="2025-06-05T16:16:54+02:00" level=debug msg="zeroconf server listening on port 40097" Jun 05 16:16:54 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:16:54 volumio go-librespot[7047]: time="2025-06-05T16:16:54+02:00" level=debug msg="obtained new client token: AAD8M/jlNbHYYcr6k9JoNTmil3yYLxVmtz5Qjz32+ILoGtoDVW8kbe58p5s/MGgEabrPXjH6fsN/aIFC4ScDqQh64CXb6BOe8Z8ffMGlz8GgYU7N0XhCIk6K8qYZtEexDM2LxIHxe8ReZ778Ty+k/2dSWG0DltGoib+Rxv4rfliERgcetnCRcr2p494hDQaYcQXLvYeIe50gZqRgmRpBEsAQNBDLrOHuIJDg/SKd9z8VMOXVxqDMRHc=" Jun 05 16:16:54 volumio go-librespot[7047]: time="2025-06-05T16:16:54+02:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.65.9:4070: connect: connection refused" Jun 05 16:16:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:16:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:16:54 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:16:54 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 16:16:55 volumio volumio[1039]: info: sendMpdCommand status took 3664 milliseconds Jun 05 16:16:55 volumio volumio[1039]: info: sendMpdCommand status took 3663 milliseconds Jun 05 16:16:55 volumio volumio[1039]: info: sendMpdCommand status took 3664 milliseconds Jun 05 16:16:55 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:16:55 volumio volumio[1039]: info: Command Router : Notfying DB Updatefalse Jun 05 16:16:55 volumio volumio[1039]: info: CoreCommandRouter::Close All Modals sent Jun 05 16:16:55 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:16:55 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 16:16:55 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:16:55 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 16:16:57 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:16:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 217. Jun 05 16:16:57 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:16:57 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:16:57 volumio go-librespot[7062]: Librespot-go daemon starting... Jun 05 16:16:57 volumio go-librespot[7062]: time="2025-06-05T16:16:57+02:00" level=info msg="generated new device id: d9f7873677c1ab02c34294e7e5eb337fbe6fc784" Jun 05 16:16:57 volumio go-librespot[7062]: time="2025-06-05T16:16:57+02:00" level=debug msg="stored credentials not found" Jun 05 16:16:57 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:16:57 volumio go-librespot[7062]: time="2025-06-05T16:16:57+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 05 16:16:57 volumio go-librespot[7062]: time="2025-06-05T16:16:57+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 05 16:16:57 volumio go-librespot[7062]: time="2025-06-05T16:16:57+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 05 16:16:57 volumio go-librespot[7062]: time="2025-06-05T16:16:57+02:00" level=debug msg="zeroconf server listening on port 41953" Jun 05 16:16:57 volumio go-librespot[7062]: time="2025-06-05T16:16:57+02:00" level=debug msg="obtained new client token: AACX2DCXzipuCKRjq4IompW11xWAHTuS9jx4XTGkYKQe1hiUq0M6A0TooeVR8pdiL1l3EIAPS9syKcbebbUaTsZi/kl5cu+dsbQVemkMsrC2Ir4bi+aBQ2oKPtanjIuxCKh6pr3MY0wNXQhCB2wunGoCyYzaZHShodbn9MFJfKFqHv9KhaWz5b5P0uPTMS0oNVNd9aAYRPUZVjFu19yeERfbnyHOBNYN4k8pclbgkyT1RKrBN/0bdxtJOg==" Jun 05 16:16:57 volumio go-librespot[7062]: time="2025-06-05T16:16:57+02:00" level=debug msg="completed keyexchange" Jun 05 16:16:58 volumio volumio[1039]: info: sendMpdCommand status took 6542 milliseconds Jun 05 16:16:58 volumio volumio[1039]: info: sendMpdCommand status took 6542 milliseconds Jun 05 16:16:58 volumio volumio[1039]: info: sendMpdCommand status took 6542 milliseconds Jun 05 16:16:58 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:16:58 volumio volumio[1039]: info: Command Router : Notfying DB Updatefalse Jun 05 16:16:58 volumio volumio[1039]: info: CoreCommandRouter::Close All Modals sent Jun 05 16:16:58 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:16:58 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 16:16:58 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:16:58 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 16:16:58 volumio go-librespot[7062]: time="2025-06-05T16:16:58+02:00" level=debug msg="completed challenge" Jun 05 16:16:58 volumio go-librespot[7062]: time="2025-06-05T16:16:58+02:00" level=debug msg="new websocket client" Jun 05 16:16:58 volumio volumio[1039]: info: Connection to go-librespot Websocket established Jun 05 16:16:58 volumio go-librespot[7062]: time="2025-06-05T16:16:58+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Jun 05 16:16:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:16:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:16:58 volumio volumio[1039]: info: Connection to go-librespot Websocket closed Jun 05 16:16:58 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 16:17:01 volumio volumio[1039]: info: sendMpdCommand status took 9427 milliseconds Jun 05 16:17:01 volumio volumio[1039]: info: sendMpdCommand status took 9427 milliseconds Jun 05 16:17:01 volumio volumio[1039]: info: sendMpdCommand status took 9426 milliseconds Jun 05 16:17:01 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:17:01 volumio volumio[1039]: info: Command Router : Notfying DB Updatefalse Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::Close All Modals sent Jun 05 16:17:01 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:17:01 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 16:17:01 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:17:01 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 16:17:01 volumio volumio[1039]: info: sendMpdCommand playlistinfo took 5738 milliseconds Jun 05 16:17:01 volumio volumio[1039]: info: sendMpdCommand playlistinfo took 5737 milliseconds Jun 05 16:17:01 volumio volumio[1039]: verbose: ControllerMpd::parseTrackInfo Jun 05 16:17:01 volumio volumio[1039]: info: ControllerMpd::pushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::servicePushState Jun 05 16:17:01 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:01 volumio volumio[1039]: verbose: STATE SERVICE {"status":"play","position":0,"seek":811931,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Nnenna Freelon - Black Orchid","artist":"Radio Jazz","album":null,"uri":"http://online.radiojazz.ua/RadioJazz_HD","trackType":""} Jun 05 16:17:01 volumio volumio[1039]: verbose: CURRENT POSITION 0 Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::syncState stateService play Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::syncState currentStatus play Jun 05 16:17:01 volumio volumio[1039]: info: Received an update from plugin. extracting info from payload Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:01 volumio volumio[1039]: info: ControllerMpd::pushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::servicePushState Jun 05 16:17:01 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:01 volumio volumio[1039]: verbose: STATE SERVICE {"status":"play","position":0,"seek":811931,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Nnenna Freelon - Black Orchid","artist":"Radio Jazz","album":null,"uri":"http://online.radiojazz.ua/RadioJazz_HD","trackType":""} Jun 05 16:17:01 volumio volumio[1039]: verbose: CURRENT POSITION 0 Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::syncState stateService play Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::syncState currentStatus play Jun 05 16:17:01 volumio volumio[1039]: info: Received an update from plugin. extracting info from payload Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:01 volumio volumio[1039]: info: ------------------------------ 9503ms Jun 05 16:17:01 volumio volumio[1039]: info: ------------------------------ 9503ms Jun 05 16:17:01 volumio volumio[1039]: info: sendMpdCommand playlistinfo took 2915 milliseconds Jun 05 16:17:01 volumio volumio[1039]: info: sendMpdCommand playlistinfo took 2916 milliseconds Jun 05 16:17:01 volumio volumio[1039]: verbose: ControllerMpd::parseTrackInfo Jun 05 16:17:01 volumio volumio[1039]: verbose: ControllerMpd::parseTrackInfo Jun 05 16:17:01 volumio volumio[1039]: info: ControllerMpd::pushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::servicePushState Jun 05 16:17:01 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:01 volumio volumio[1039]: verbose: STATE SERVICE {"status":"play","position":0,"seek":812182,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Nnenna Freelon - Black Orchid","artist":"Radio Jazz","album":null,"uri":"http://online.radiojazz.ua/RadioJazz_HD","trackType":""} Jun 05 16:17:01 volumio volumio[1039]: verbose: CURRENT POSITION 0 Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::syncState stateService play Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::syncState currentStatus play Jun 05 16:17:01 volumio volumio[1039]: info: Received an update from plugin. extracting info from payload Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:01 volumio volumio[1039]: info: ControllerMpd::pushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::servicePushState Jun 05 16:17:01 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:01 volumio volumio[1039]: verbose: STATE SERVICE {"status":"play","position":0,"seek":812182,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Nnenna Freelon - Black Orchid","artist":"Radio Jazz","album":null,"uri":"http://online.radiojazz.ua/RadioJazz_HD","trackType":""} Jun 05 16:17:01 volumio volumio[1039]: verbose: CURRENT POSITION 0 Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::syncState stateService play Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::syncState currentStatus play Jun 05 16:17:01 volumio volumio[1039]: info: Received an update from plugin. extracting info from payload Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:01 volumio volumio[1039]: info: ------------------------------ 9519ms Jun 05 16:17:01 volumio volumio[1039]: info: ------------------------------ 9519ms Jun 05 16:17:01 volumio volumio[1039]: info: sendMpdCommand playlistinfo took 63 milliseconds Jun 05 16:17:01 volumio volumio[1039]: info: sendMpdCommand playlistinfo took 64 milliseconds Jun 05 16:17:01 volumio volumio[1039]: verbose: ControllerMpd::parseTrackInfo Jun 05 16:17:01 volumio volumio[1039]: verbose: ControllerMpd::parseTrackInfo Jun 05 16:17:01 volumio volumio[1039]: info: ControllerMpd::pushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::servicePushState Jun 05 16:17:01 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:01 volumio volumio[1039]: verbose: STATE SERVICE {"status":"play","position":0,"seek":812434,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Nnenna Freelon - Black Orchid","artist":"Radio Jazz","album":null,"uri":"http://online.radiojazz.ua/RadioJazz_HD","trackType":""} Jun 05 16:17:01 volumio volumio[1039]: verbose: CURRENT POSITION 0 Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::syncState stateService play Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::syncState currentStatus play Jun 05 16:17:01 volumio volumio[1039]: info: Received an update from plugin. extracting info from payload Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:01 volumio volumio[1039]: info: ControllerMpd::pushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::servicePushState Jun 05 16:17:01 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:01 volumio volumio[1039]: verbose: STATE SERVICE {"status":"play","position":0,"seek":812434,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Nnenna Freelon - Black Orchid","artist":"Radio Jazz","album":null,"uri":"http://online.radiojazz.ua/RadioJazz_HD","trackType":""} Jun 05 16:17:01 volumio volumio[1039]: verbose: CURRENT POSITION 0 Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::syncState stateService play Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::syncState currentStatus play Jun 05 16:17:01 volumio volumio[1039]: info: Received an update from plugin. extracting info from payload Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:01 volumio volumio[1039]: info: ------------------------------ 9540ms Jun 05 16:17:01 volumio volumio[1039]: info: ------------------------------ 9540ms Jun 05 16:17:01 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:01 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:01 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:01 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:01 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:01 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:01 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:01 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:01 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:01 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:01 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:01 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:01 volumio volumio[1039]: info: Getting Spotify volume Jun 05 16:17:01 volumio volumio[1039]: (node:1039) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:17:01 volumio volumio[1039]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 05 16:17:01 volumio volumio[1039]: (node:1039) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 66) Jun 05 16:17:01 volumio volumio[1039]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jun 05 16:17:01 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:17:01 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:17:01 volumio volumio[1039]: info: CoreCommandRouter::volumioGetState Jun 05 16:17:01 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:17:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 218. Jun 05 16:17:01 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:17:01 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:17:01 volumio go-librespot[7095]: Librespot-go daemon starting... Jun 05 16:17:01 volumio go-librespot[7095]: time="2025-06-05T16:17:01+02:00" level=info msg="generated new device id: a27c15aee541e0a7f8503ff71535107b816c912b" Jun 05 16:17:01 volumio go-librespot[7095]: time="2025-06-05T16:17:01+02:00" level=debug msg="stored credentials not found" Jun 05 16:17:01 volumio go-librespot[7095]: time="2025-06-05T16:17:01+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 05 16:17:01 volumio go-librespot[7095]: time="2025-06-05T16:17:01+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 05 16:17:01 volumio go-librespot[7095]: time="2025-06-05T16:17:01+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 05 16:17:01 volumio go-librespot[7095]: time="2025-06-05T16:17:01+02:00" level=debug msg="zeroconf server listening on port 39287" Jun 05 16:17:01 volumio go-librespot[7095]: time="2025-06-05T16:17:01+02:00" level=debug msg="obtained new client token: AADuBCJ3keU8iaYLhPklHSn1b9157bMpitdFvkDa/6BsePZsV61O6sf7BPJ1mnvxK9ZWGsI5ID10PhqAXol0+LZQRVIR6PayZLu7mcDW32vcRGOPT4zdMje/wcRVYyKhcQJrZYzu5oQWDLFwpxedHA7ajg0PjoRW+yNiQQyeChSZnI/3Ew/2GMnWQv6/D02tEZH1prGOrJzwX778pqn/QDgqbTVzWo7b4Zco+7O/GkqW7Lf5IdKHXpSDFQ==" Jun 05 16:17:02 volumio go-librespot[7095]: time="2025-06-05T16:17:02+02:00" level=debug msg="completed keyexchange" Jun 05 16:17:02 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 16:17:02 volumio go-librespot[7095]: time="2025-06-05T16:17:02+02:00" level=debug msg="completed challenge" Jun 05 16:17:02 volumio go-librespot[7095]: time="2025-06-05T16:17:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Jun 05 16:17:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:17:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:17:04 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:17:04 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:17:04 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 05 16:17:04 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 05 16:17:04 volumio volumio[1039]: info: Discovery: Getting this device information Jun 05 16:17:04 volumio volumio[1039]: info: CoreCommandRouter::volumioGetState Jun 05 16:17:04 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 05 16:17:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:17:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 219. Jun 05 16:17:05 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:17:05 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:17:05 volumio go-librespot[7112]: Librespot-go daemon starting... Jun 05 16:17:05 volumio go-librespot[7112]: time="2025-06-05T16:17:05+02:00" level=info msg="generated new device id: 4dbf3b94628725e6fb8efb764fcd335f61196de0" Jun 05 16:17:05 volumio go-librespot[7112]: time="2025-06-05T16:17:05+02:00" level=debug msg="stored credentials not found" Jun 05 16:17:06 volumio go-librespot[7112]: time="2025-06-05T16:17:06+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 05 16:17:06 volumio go-librespot[7112]: time="2025-06-05T16:17:06+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 05 16:17:06 volumio go-librespot[7112]: time="2025-06-05T16:17:06+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 05 16:17:06 volumio go-librespot[7112]: time="2025-06-05T16:17:06+02:00" level=debug msg="zeroconf server listening on port 35557" Jun 05 16:17:06 volumio go-librespot[7112]: time="2025-06-05T16:17:06+02:00" level=debug msg="obtained new client token: AADvx9IlBsg4g9qxSYQxLjw2NfVtCebP7LAPkBRkq/jiJYcHx2y5lhFkz+M8Uh3UuVSSPpqN4Sgaqbc4TgGuui7VzgmSyz/zplakHenInfg7DjcWOqN7EeBU0PnRNLIj/oBTSNV7Jsf8FRopz4x+4ucGTUqm/7GbkTt/MrMRoL+BQQzDZDIFw6m4n8wXWCx1FWGZ99+w3mPbKCPQxIpw1TzkVzKP/3T8pIRwKaacNVhScJ2/ACm/Ndc=" Jun 05 16:17:06 volumio go-librespot[7112]: time="2025-06-05T16:17:06+02:00" level=debug msg="completed keyexchange" Jun 05 16:17:06 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 16:17:06 volumio go-librespot[7112]: time="2025-06-05T16:17:06+02:00" level=debug msg="completed challenge" Jun 05 16:17:06 volumio go-librespot[7112]: time="2025-06-05T16:17:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Jun 05 16:17:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:17:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:17:07 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:17:07 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:17:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:17:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 220. Jun 05 16:17:09 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:17:09 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:17:09 volumio go-librespot[7132]: Librespot-go daemon starting... Jun 05 16:17:09 volumio go-librespot[7132]: time="2025-06-05T16:17:09+02:00" level=info msg="generated new device id: b09f8cf47bc505f12e66f150577e7f4257935d25" Jun 05 16:17:09 volumio go-librespot[7132]: time="2025-06-05T16:17:09+02:00" level=debug msg="stored credentials not found" Jun 05 16:17:10 volumio go-librespot[7132]: time="2025-06-05T16:17:10+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 05 16:17:10 volumio go-librespot[7132]: time="2025-06-05T16:17:10+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 05 16:17:10 volumio go-librespot[7132]: time="2025-06-05T16:17:10+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 05 16:17:10 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jun 05 16:17:10 volumio volumio[1039]: info: CURURI: music-library/NAS Jun 05 16:17:10 volumio go-librespot[7132]: time="2025-06-05T16:17:10+02:00" level=debug msg="zeroconf server listening on port 43521" Jun 05 16:17:10 volumio volumio[1039]: info: Preload queue cleared Jun 05 16:17:10 volumio go-librespot[7132]: time="2025-06-05T16:17:10+02:00" level=debug msg="obtained new client token: AAAI2//M6TxXNeyyEaQ+w+MvXV418n/gpa6ODIIRUP3CGyV3rJrd62rSiSPGz3WTM0zFdZsQ/SOSKBU9Kjn/qUhRHd9T23TTvRHGJgSil4JWi4F+Y2JHBm9yCIK7c4FJWDrVDOsi71RocpA9gTyp4KLlANy9jSgb54korRJ/tvuXuaPRfTwN8FbV9yT8DebT6wSe5hUN++V0DO9R/j5EyhM1jZf8u7KxgIrwvKkg36TKz/p3w9sx7Ik=" Jun 05 16:17:10 volumio go-librespot[7132]: time="2025-06-05T16:17:10+02:00" level=debug msg="completed keyexchange" Jun 05 16:17:10 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:17:10 volumio go-librespot[7132]: time="2025-06-05T16:17:10+02:00" level=debug msg="new websocket client" Jun 05 16:17:10 volumio volumio[1039]: info: Connection to go-librespot Websocket established Jun 05 16:17:10 volumio go-librespot[7132]: time="2025-06-05T16:17:10+02:00" level=debug msg="completed challenge" Jun 05 16:17:10 volumio go-librespot[7132]: time="2025-06-05T16:17:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Jun 05 16:17:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:17:10 volumio volumio[1039]: info: Connection to go-librespot Websocket closed Jun 05 16:17:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:17:11 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jun 05 16:17:11 volumio volumio[1039]: info: CURURI: music-library/NAS/Servidor-Salita Jun 05 16:17:11 volumio volumio[1039]: info: Preload queue cleared Jun 05 16:17:13 volumio volumio[1039]: info: Getting Spotify volume Jun 05 16:17:13 volumio volumio[1039]: (node:1039) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:17:13 volumio volumio[1039]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 05 16:17:13 volumio volumio[1039]: (node:1039) 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: 67) Jun 05 16:17:13 volumio volumio[1039]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jun 05 16:17:13 volumio volumio[1039]: info: CoreCommandRouter::volumioGetState Jun 05 16:17:13 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:13 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:17:13 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:17:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:17:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 221. Jun 05 16:17:14 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:17:14 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:17:14 volumio go-librespot[7162]: Librespot-go daemon starting... Jun 05 16:17:14 volumio go-librespot[7162]: time="2025-06-05T16:17:14+02:00" level=info msg="generated new device id: fc8d0b4650ac3ea273eb07a0283357d8ae46ef0b" Jun 05 16:17:14 volumio go-librespot[7162]: time="2025-06-05T16:17:14+02:00" level=debug msg="stored credentials not found" Jun 05 16:17:14 volumio go-librespot[7162]: time="2025-06-05T16:17:14+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 05 16:17:14 volumio go-librespot[7162]: time="2025-06-05T16:17:14+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 05 16:17:14 volumio go-librespot[7162]: time="2025-06-05T16:17:14+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 05 16:17:14 volumio go-librespot[7162]: time="2025-06-05T16:17:14+02:00" level=debug msg="zeroconf server listening on port 41383" Jun 05 16:17:14 volumio go-librespot[7162]: time="2025-06-05T16:17:14+02:00" level=debug msg="obtained new client token: AAAwErWsfMNVCo1+9/IXcUW9Do4DRt6YK5aiWAEdkNSVMC7L6pv7kzx4VEfwKvtemaPE13kHa40YAsAsACgcZMVSIXHGtCwvKSOu3/cbfdeAhFVNTnTNPrmf5VhtwOCqh0SHdDhNiMvpDPHHj1XCBVYE1BfmV/4RR54JYe0B1hLZ5kLAu+gAG0GuRiMQs2tO66JlCAQIW9idhaL6Hz/DzwXcgYAFjTe7gRt/d3HxXnCUy+8aauTOSPdeQA==" Jun 05 16:17:14 volumio go-librespot[7162]: time="2025-06-05T16:17:14+02:00" level=debug msg="completed keyexchange" Jun 05 16:17:14 volumio go-librespot[7162]: time="2025-06-05T16:17:14+02:00" level=debug msg="completed challenge" Jun 05 16:17:14 volumio go-librespot[7162]: time="2025-06-05T16:17:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Jun 05 16:17:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:17:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:17:16 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:17:16 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:17:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:17:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 222. Jun 05 16:17:18 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:17:18 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:17:18 volumio go-librespot[7178]: Librespot-go daemon starting... Jun 05 16:17:18 volumio go-librespot[7178]: time="2025-06-05T16:17:18+02:00" level=info msg="generated new device id: d0769a40e4909beed3001cfe3fbe7e05c234430f" Jun 05 16:17:18 volumio go-librespot[7178]: time="2025-06-05T16:17:18+02:00" level=debug msg="stored credentials not found" Jun 05 16:17:18 volumio go-librespot[7178]: time="2025-06-05T16:17:18+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 05 16:17:18 volumio go-librespot[7178]: time="2025-06-05T16:17:18+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 05 16:17:18 volumio go-librespot[7178]: time="2025-06-05T16:17:18+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 05 16:17:18 volumio go-librespot[7178]: time="2025-06-05T16:17:18+02:00" level=debug msg="zeroconf server listening on port 37287" Jun 05 16:17:18 volumio go-librespot[7178]: time="2025-06-05T16:17:18+02:00" level=debug msg="obtained new client token: AABU5JaUYM8hv5alIiHKzmmucO/MhrxmxlB7XiHAPEj2mD7APcqUmMNQ2MxKltLGFbx8IQs1fLy6hEY3AR70i+t4tLhOo7pGN/P+0qz5xQ+x9iepOV1L6whmyufrTxpBgBMarrLRCz0tReymWefk7t7ed6IIUb4mKV8ll4G96hM9JkpIWqV8Yp+uBTFl6cqGzSCSi5rrWMkvUJwY1j7TtjlLHmGW4c8ogBtzRre10vQxd3Y/4CjZMWpVfg==" Jun 05 16:17:18 volumio go-librespot[7178]: time="2025-06-05T16:17:18+02:00" level=debug msg="completed keyexchange" Jun 05 16:17:18 volumio go-librespot[7178]: time="2025-06-05T16:17:18+02:00" level=debug msg="completed challenge" Jun 05 16:17:18 volumio go-librespot[7178]: time="2025-06-05T16:17:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Jun 05 16:17:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 05 16:17:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 05 16:17:19 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:17:19 volumio volumio[1039]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 05 16:17:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 05 16:17:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 223. Jun 05 16:17:22 volumio systemd[1]: Stopped go-librespot Daemon. Jun 05 16:17:22 volumio systemd[1]: Started go-librespot Daemon. Jun 05 16:17:22 volumio go-librespot[7211]: Librespot-go daemon starting... Jun 05 16:17:22 volumio go-librespot[7211]: time="2025-06-05T16:17:22+02:00" level=info msg="generated new device id: 976d616c9010b64a7d2b6a2636575458178f2111" Jun 05 16:17:22 volumio go-librespot[7211]: time="2025-06-05T16:17:22+02:00" level=debug msg="stored credentials not found" Jun 05 16:17:22 volumio go-librespot[7211]: time="2025-06-05T16:17:22+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 05 16:17:22 volumio go-librespot[7211]: time="2025-06-05T16:17:22+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 05 16:17:22 volumio go-librespot[7211]: time="2025-06-05T16:17:22+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 05 16:17:22 volumio go-librespot[7211]: time="2025-06-05T16:17:22+02:00" level=debug msg="zeroconf server listening on port 37371" Jun 05 16:17:22 volumio go-librespot[7211]: time="2025-06-05T16:17:22+02:00" level=debug msg="obtained new client token: AABMLAut5rGGllvYP6qnviBS6f+P8WcE5nWoP+oU8/YOBdk3Kw4OrRWqDnwa3LJmW3gkxzi+n1N2RLWWD1ALgFBIown82ADzq57mlyNjVW9lbr/L6xF4E9525CMdiX6lc6fIm6JmC4MahhQ3un5Q1Fn9Ee8PFZHSCwX4hGrUPjxd9OxiVBhDQT5Y55d+XsLnt2NBpwID/x6pk+M3lcMO4vBFiKxxQcQhgafDYy5Y1aoLMIWIXCZYPA5tzA==" Jun 05 16:17:22 volumio volumio[1039]: info: Initializing connection to go-librespot Websocket Jun 05 16:17:22 volumio go-librespot[7211]: time="2025-06-05T16:17:22+02:00" level=debug msg="new websocket client" Jun 05 16:17:22 volumio volumio[1039]: info: Connection to go-librespot Websocket established Jun 05 16:17:23 volumio volumio[1039]: info: Jun 05 16:17:23 volumio volumio[1039]: ---------------------------- MPD announces system playlist update Jun 05 16:17:23 volumio volumio[1039]: info: Ignoring MPD Status Update Jun 05 16:17:23 volumio volumio[1039]: info: Jun 05 16:17:23 volumio volumio[1039]: ---------------------------- MPD announces state update: player Jun 05 16:17:23 volumio volumio[1039]: info: ControllerMpd::getState Jun 05 16:17:23 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:17:23 volumio volumio[1039]: info: Jun 05 16:17:23 volumio volumio[1039]: ---------------------------- MPD announces system playlist update Jun 05 16:17:23 volumio volumio[1039]: info: Ignoring MPD Status Update Jun 05 16:17:23 volumio volumio[1039]: info: Jun 05 16:17:23 volumio volumio[1039]: ---------------------------- MPD announces state update: player Jun 05 16:17:23 volumio volumio[1039]: info: ControllerMpd::getState Jun 05 16:17:23 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:17:23 volumio volumio[1039]: info: Jun 05 16:17:23 volumio volumio[1039]: ---------------------------- MPD announces system playlist update Jun 05 16:17:23 volumio volumio[1039]: info: Ignoring MPD Status Update Jun 05 16:17:23 volumio volumio[1039]: info: Jun 05 16:17:23 volumio volumio[1039]: ---------------------------- MPD announces state update: player Jun 05 16:17:23 volumio volumio[1039]: info: ControllerMpd::getState Jun 05 16:17:23 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:17:23 volumio volumio[1039]: info: ------------------------------ 8ms Jun 05 16:17:23 volumio volumio[1039]: info: sendMpdCommand status took 6 milliseconds Jun 05 16:17:23 volumio volumio[1039]: info: ------------------------------ 6ms Jun 05 16:17:23 volumio volumio[1039]: info: sendMpdCommand status took 4 milliseconds Jun 05 16:17:23 volumio volumio[1039]: info: ------------------------------ 4ms Jun 05 16:17:23 volumio volumio[1039]: info: sendMpdCommand status took 4 milliseconds Jun 05 16:17:23 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:17:23 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 16:17:23 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:17:23 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 16:17:23 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:17:23 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 16:17:23 volumio volumio[1039]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 05 16:17:23 volumio volumio[1039]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 05 16:17:23 volumio volumio[1039]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 05 16:17:23 volumio volumio[1039]: verbose: ControllerMpd::parseTrackInfo Jun 05 16:17:23 volumio volumio[1039]: verbose: ControllerMpd::parseTrackInfo Jun 05 16:17:23 volumio volumio[1039]: verbose: ControllerMpd::parseTrackInfo Jun 05 16:17:23 volumio volumio[1039]: info: ControllerMpd::pushState Jun 05 16:17:23 volumio volumio[1039]: info: CoreCommandRouter::servicePushState Jun 05 16:17:23 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:23 volumio volumio[1039]: verbose: STATE SERVICE {"status":"play","position":0,"seek":844057,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Radio Jazz - www.radiojazz.ua","artist":"Radio Jazz","album":null,"uri":"http://online.radiojazz.ua/RadioJazz_HD","trackType":""} Jun 05 16:17:23 volumio volumio[1039]: verbose: CURRENT POSITION 0 Jun 05 16:17:23 volumio volumio[1039]: info: CoreStateMachine::syncState stateService play Jun 05 16:17:23 volumio volumio[1039]: info: CoreStateMachine::syncState currentStatus play Jun 05 16:17:23 volumio volumio[1039]: info: Received an update from plugin. extracting info from payload Jun 05 16:17:23 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jun 05 16:17:23 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:23 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 16:17:23 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:23 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:23 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:23 volumio volumio[1039]: info: ControllerMpd::pushState Jun 05 16:17:23 volumio volumio[1039]: info: CoreCommandRouter::servicePushState Jun 05 16:17:23 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:23 volumio volumio[1039]: verbose: STATE SERVICE {"status":"play","position":0,"seek":844057,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Radio Jazz - www.radiojazz.ua","artist":"Radio Jazz","album":null,"uri":"http://online.radiojazz.ua/RadioJazz_HD","trackType":""} Jun 05 16:17:23 volumio volumio[1039]: verbose: CURRENT POSITION 0 Jun 05 16:17:23 volumio volumio[1039]: info: CoreStateMachine::syncState stateService play Jun 05 16:17:23 volumio volumio[1039]: info: CoreStateMachine::syncState currentStatus play Jun 05 16:17:23 volumio volumio[1039]: info: Received an update from plugin. extracting info from payload Jun 05 16:17:23 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jun 05 16:17:23 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:23 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:23 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:23 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:23 volumio volumio[1039]: info: ControllerMpd::pushState Jun 05 16:17:23 volumio volumio[1039]: info: CoreCommandRouter::servicePushState Jun 05 16:17:23 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:23 volumio volumio[1039]: verbose: STATE SERVICE {"status":"play","position":0,"seek":844057,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Radio Jazz - www.radiojazz.ua","artist":"Radio Jazz","album":null,"uri":"http://online.radiojazz.ua/RadioJazz_HD","trackType":""} Jun 05 16:17:23 volumio volumio[1039]: verbose: CURRENT POSITION 0 Jun 05 16:17:23 volumio volumio[1039]: info: CoreStateMachine::syncState stateService play Jun 05 16:17:23 volumio volumio[1039]: info: CoreStateMachine::syncState currentStatus play Jun 05 16:17:23 volumio volumio[1039]: info: Received an update from plugin. extracting info from payload Jun 05 16:17:23 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jun 05 16:17:23 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:23 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:23 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:23 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:23 volumio volumio[1039]: info: ------------------------------ 41ms Jun 05 16:17:23 volumio volumio[1039]: info: ------------------------------ 39ms Jun 05 16:17:23 volumio volumio[1039]: info: ------------------------------ 37ms Jun 05 16:17:23 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:23 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:23 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:23 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:23 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:23 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:25 volumio volumio[1039]: info: Getting Spotify volume Jun 05 16:17:25 volumio volumio[1039]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jun 05 16:17:25 volumio volumio[1039]: info: CoreCommandRouter::volumioGetState Jun 05 16:17:25 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:29 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jun 05 16:17:29 volumio volumio[1039]: info: CURURI: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac') Jun 05 16:17:29 volumio volumio[1039]: info: Preload queue cleared Jun 05 16:17:29 volumio volumio[1039]: info: Preloading song: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-01 Rock Steady - ('Young, Gifted and Black').flac Jun 05 16:17:29 volumio volumio[1039]: info: Preloading song: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-02 Young, Gifted and Black - ('Young, Gifted and Black').flac Jun 05 16:17:29 volumio volumio[1039]: info: Preloading song: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-03 All the King's Horses - ('Young, Gifted and Black').flac Jun 05 16:17:29 volumio volumio[1039]: info: Preloading song: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-04 Oh Me Oh My (I'm a Fool for You Baby) - ('Young, Gifted and Black').flac Jun 05 16:17:29 volumio volumio[1039]: info: Preloading song: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-05 Day Dreaming - ('Young, Gifted and Black').flac Jun 05 16:17:29 volumio volumio[1039]: info: Preloading song: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-06 Mary, Don't You Weep - (Live at New Temple Missionary Baptist Church, Los Angeles, January 14, 1972).flac Jun 05 16:17:29 volumio volumio[1039]: info: Preloading song: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-07 Climbing Higher Mountains - (Live at New Temple Missionary Baptist Church, Los Angeles, January 14, 1972).flac Jun 05 16:17:29 volumio volumio[1039]: info: Preloading song: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-08 Precious Memories - (Live at New Temple Missionary Baptist Church, Los Angeles, January 14, 1972).flac Jun 05 16:17:29 volumio volumio[1039]: info: Preloading song: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-09 Master of Eyes (The Deepness of Your Eyes) - ('Hey Now Hey (The Other Side of the Sky)').flac Jun 05 16:17:29 volumio volumio[1039]: info: Preloading song: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-10 Angel - ('Hey Now Hey (The Other Side of the Sky)').flac Jun 05 16:17:29 volumio volumio[1039]: info: Preloading song: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-11 Somewhere - ('Hey Now Hey (The Other Side of the Sky)').flac Jun 05 16:17:29 volumio volumio[1039]: info: Preloading song: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-12 So Swell When You're Well - ('Hey Now Hey (The Other Side of the Sky)').flac Jun 05 16:17:29 volumio volumio[1039]: info: Preloading song: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-13 I'm in Love - ('Let Me in Your Life').flac Jun 05 16:17:29 volumio volumio[1039]: info: Preloading song: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-14 Ain't Nothing Like the Real Thing - ('Let Me in Your Life').flac Jun 05 16:17:29 volumio volumio[1039]: info: Preloading song: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-15 Until You Come Back to Me (That's What I'm Gonna Do) - ('Let Me in Your Life').flac Jun 05 16:17:29 volumio volumio[1039]: info: Preloading song: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-16 Look into Your Heart - ('Sparkle').flac Jun 05 16:17:29 volumio volumio[1039]: info: Preloading song: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-17 Sparkle - ('Sparkle').flac Jun 05 16:17:29 volumio volumio[1039]: info: Preloading song: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-18 Something He Can Feel - ('Sparkle').flac Jun 05 16:17:29 volumio volumio[1039]: info: Exploding uri music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-01 Rock Steady - ('Young, Gifted and Black').flac in service mpd Jun 05 16:17:29 volumio volumio[1039]: info: ALBUMART /albumart?cacheid=902&web=Aretha%20Franklin/The%20Queen%20of%20Soul/medium&path=%2Fmnt%2FNAS%2FServidor-Salita%2F4_Aretha%20Franklin%20-2014-%20The%20Queen%20of%20Soul%204%20(1967-1976)%5B24bit_192kHz%5D(AcousticSounds)(flac')%2F4-01%20Rock%20Steady%20-%20('Young%2C%20Gifted%20and%20Black').flac&metadata=false Jun 05 16:17:29 volumio volumio[1039]: info: URI /mnt/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-01 Rock Steady - ('Young, Gifted and Black').flac Jun 05 16:17:29 volumio volumio[1039]: info: Exploding uri music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-02 Young, Gifted and Black - ('Young, Gifted and Black').flac in service mpd Jun 05 16:17:29 volumio volumio[1039]: info: ALBUMART /albumart?cacheid=902&web=Aretha%20Franklin/The%20Queen%20of%20Soul/medium&path=%2Fmnt%2FNAS%2FServidor-Salita%2F4_Aretha%20Franklin%20-2014-%20The%20Queen%20of%20Soul%204%20(1967-1976)%5B24bit_192kHz%5D(AcousticSounds)(flac')%2F4-02%20Young%2C%20Gifted%20and%20Black%20-%20('Young%2C%20Gifted%20and%20Black').flac&metadata=false Jun 05 16:17:29 volumio volumio[1039]: info: URI /mnt/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-02 Young, Gifted and Black - ('Young, Gifted and Black').flac Jun 05 16:17:29 volumio volumio[1039]: info: Exploding uri music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-03 All the King's Horses - ('Young, Gifted and Black').flac in service mpd Jun 05 16:17:29 volumio volumio[1039]: info: ALBUMART /albumart?cacheid=902&web=Aretha%20Franklin/The%20Queen%20of%20Soul/medium&path=%2Fmnt%2FNAS%2FServidor-Salita%2F4_Aretha%20Franklin%20-2014-%20The%20Queen%20of%20Soul%204%20(1967-1976)%5B24bit_192kHz%5D(AcousticSounds)(flac')%2F4-03%20All%20the%20King's%20Horses%20-%20('Young%2C%20Gifted%20and%20Black').flac&metadata=false Jun 05 16:17:29 volumio volumio[1039]: info: URI /mnt/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-03 All the King's Horses - ('Young, Gifted and Black').flac Jun 05 16:17:29 volumio volumio[1039]: info: Exploding uri music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-04 Oh Me Oh My (I'm a Fool for You Baby) - ('Young, Gifted and Black').flac in service mpd Jun 05 16:17:29 volumio volumio[1039]: info: ALBUMART /albumart?cacheid=902&web=Aretha%20Franklin/The%20Queen%20of%20Soul/medium&path=%2Fmnt%2FNAS%2FServidor-Salita%2F4_Aretha%20Franklin%20-2014-%20The%20Queen%20of%20Soul%204%20(1967-1976)%5B24bit_192kHz%5D(AcousticSounds)(flac')%2F4-04%20Oh%20Me%20Oh%20My%20(I'm%20a%20Fool%20for%20You%20Baby)%20-%20('Young%2C%20Gifted%20and%20Black').flac&metadata=false Jun 05 16:17:29 volumio volumio[1039]: info: URI /mnt/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-04 Oh Me Oh My (I'm a Fool for You Baby) - ('Young, Gifted and Black').flac Jun 05 16:17:29 volumio volumio[1039]: info: Exploding uri music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-05 Day Dreaming - ('Young, Gifted and Black').flac in service mpd Jun 05 16:17:29 volumio volumio[1039]: info: ALBUMART /albumart?cacheid=902&web=Aretha%20Franklin/The%20Queen%20of%20Soul/medium&path=%2Fmnt%2FNAS%2FServidor-Salita%2F4_Aretha%20Franklin%20-2014-%20The%20Queen%20of%20Soul%204%20(1967-1976)%5B24bit_192kHz%5D(AcousticSounds)(flac')%2F4-05%20Day%20Dreaming%20-%20('Young%2C%20Gifted%20and%20Black').flac&metadata=false Jun 05 16:17:29 volumio volumio[1039]: info: URI /mnt/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-05 Day Dreaming - ('Young, Gifted and Black').flac Jun 05 16:17:29 volumio volumio[1039]: info: Exploding uri music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-06 Mary, Don't You Weep - (Live at New Temple Missionary Baptist Church, Los Angeles, January 14, 1972).flac in service mpd Jun 05 16:17:29 volumio volumio[1039]: info: ALBUMART /albumart?cacheid=902&web=Aretha%20Franklin/The%20Queen%20of%20Soul/medium&path=%2Fmnt%2FNAS%2FServidor-Salita%2F4_Aretha%20Franklin%20-2014-%20The%20Queen%20of%20Soul%204%20(1967-1976)%5B24bit_192kHz%5D(AcousticSounds)(flac')%2F4-06%20Mary%2C%20Don't%20You%20Weep%20-%20(Live%20at%20New%20Temple%20Missionary%20Baptist%20Church%2C%20Los%20Angeles%2C%20January%2014%2C%201972).flac&metadata=false Jun 05 16:17:29 volumio volumio[1039]: info: URI /mnt/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-06 Mary, Don't You Weep - (Live at New Temple Missionary Baptist Church, Los Angeles, January 14, 1972).flac Jun 05 16:17:29 volumio volumio[1039]: info: Exploding uri music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-07 Climbing Higher Mountains - (Live at New Temple Missionary Baptist Church, Los Angeles, January 14, 1972).flac in service mpd Jun 05 16:17:29 volumio volumio[1039]: info: ALBUMART /albumart?cacheid=902&web=Aretha%20Franklin/The%20Queen%20of%20Soul/medium&path=%2Fmnt%2FNAS%2FServidor-Salita%2F4_Aretha%20Franklin%20-2014-%20The%20Queen%20of%20Soul%204%20(1967-1976)%5B24bit_192kHz%5D(AcousticSounds)(flac')%2F4-07%20Climbing%20Higher%20Mountains%20-%20(Live%20at%20New%20Temple%20Missionary%20Baptist%20Church%2C%20Los%20Angeles%2C%20January%2014%2C%201972).flac&metadata=false Jun 05 16:17:29 volumio volumio[1039]: info: URI /mnt/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-07 Climbing Higher Mountains - (Live at New Temple Missionary Baptist Church, Los Angeles, January 14, 1972).flac Jun 05 16:17:29 volumio volumio[1039]: info: Exploding uri music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-08 Precious Memories - (Live at New Temple Missionary Baptist Church, Los Angeles, January 14, 1972).flac in service mpd Jun 05 16:17:29 volumio volumio[1039]: info: ALBUMART /albumart?cacheid=902&web=Aretha%20Franklin/The%20Queen%20of%20Soul/medium&path=%2Fmnt%2FNAS%2FServidor-Salita%2F4_Aretha%20Franklin%20-2014-%20The%20Queen%20of%20Soul%204%20(1967-1976)%5B24bit_192kHz%5D(AcousticSounds)(flac')%2F4-08%20Precious%20Memories%20-%20(Live%20at%20New%20Temple%20Missionary%20Baptist%20Church%2C%20Los%20Angeles%2C%20January%2014%2C%201972).flac&metadata=false Jun 05 16:17:29 volumio volumio[1039]: info: URI /mnt/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-08 Precious Memories - (Live at New Temple Missionary Baptist Church, Los Angeles, January 14, 1972).flac Jun 05 16:17:29 volumio volumio[1039]: info: Exploding uri music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-09 Master of Eyes (The Deepness of Your Eyes) - ('Hey Now Hey (The Other Side of the Sky)').flac in service mpd Jun 05 16:17:29 volumio volumio[1039]: info: ALBUMART /albumart?cacheid=902&web=Aretha%20Franklin/The%20Queen%20of%20Soul/medium&path=%2Fmnt%2FNAS%2FServidor-Salita%2F4_Aretha%20Franklin%20-2014-%20The%20Queen%20of%20Soul%204%20(1967-1976)%5B24bit_192kHz%5D(AcousticSounds)(flac')%2F4-09%20Master%20of%20Eyes%20(The%20Deepness%20of%20Your%20Eyes)%20-%20('Hey%20Now%20Hey%20(The%20Other%20Side%20of%20the%20Sky)').flac&metadata=false Jun 05 16:17:29 volumio volumio[1039]: info: URI /mnt/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-09 Master of Eyes (The Deepness of Your Eyes) - ('Hey Now Hey (The Other Side of the Sky)').flac Jun 05 16:17:29 volumio volumio[1039]: info: Exploding uri music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-10 Angel - ('Hey Now Hey (The Other Side of the Sky)').flac in service mpd Jun 05 16:17:29 volumio volumio[1039]: info: ALBUMART /albumart?cacheid=902&web=Aretha%20Franklin/The%20Queen%20of%20Soul/medium&path=%2Fmnt%2FNAS%2FServidor-Salita%2F4_Aretha%20Franklin%20-2014-%20The%20Queen%20of%20Soul%204%20(1967-1976)%5B24bit_192kHz%5D(AcousticSounds)(flac')%2F4-10%20Angel%20-%20('Hey%20Now%20Hey%20(The%20Other%20Side%20of%20the%20Sky)').flac&metadata=false Jun 05 16:17:29 volumio volumio[1039]: info: URI /mnt/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-10 Angel - ('Hey Now Hey (The Other Side of the Sky)').flac Jun 05 16:17:29 volumio volumio[1039]: info: Exploding uri music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-11 Somewhere - ('Hey Now Hey (The Other Side of the Sky)').flac in service mpd Jun 05 16:17:29 volumio volumio[1039]: info: ALBUMART /albumart?cacheid=902&web=Aretha%20Franklin/The%20Queen%20of%20Soul/medium&path=%2Fmnt%2FNAS%2FServidor-Salita%2F4_Aretha%20Franklin%20-2014-%20The%20Queen%20of%20Soul%204%20(1967-1976)%5B24bit_192kHz%5D(AcousticSounds)(flac')%2F4-11%20Somewhere%20-%20('Hey%20Now%20Hey%20(The%20Other%20Side%20of%20the%20Sky)').flac&metadata=false Jun 05 16:17:29 volumio volumio[1039]: info: URI /mnt/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-11 Somewhere - ('Hey Now Hey (The Other Side of the Sky)').flac Jun 05 16:17:29 volumio volumio[1039]: info: Exploding uri music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-12 So Swell When You're Well - ('Hey Now Hey (The Other Side of the Sky)').flac in service mpd Jun 05 16:17:29 volumio volumio[1039]: info: ALBUMART /albumart?cacheid=902&web=Aretha%20Franklin/The%20Queen%20of%20Soul/medium&path=%2Fmnt%2FNAS%2FServidor-Salita%2F4_Aretha%20Franklin%20-2014-%20The%20Queen%20of%20Soul%204%20(1967-1976)%5B24bit_192kHz%5D(AcousticSounds)(flac')%2F4-12%20So%20Swell%20When%20You're%20Well%20-%20('Hey%20Now%20Hey%20(The%20Other%20Side%20of%20the%20Sky)').flac&metadata=false Jun 05 16:17:29 volumio volumio[1039]: info: URI /mnt/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-12 So Swell When You're Well - ('Hey Now Hey (The Other Side of the Sky)').flac Jun 05 16:17:29 volumio volumio[1039]: info: Exploding uri music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-13 I'm in Love - ('Let Me in Your Life').flac in service mpd Jun 05 16:17:29 volumio volumio[1039]: info: ALBUMART /albumart?cacheid=902&web=Aretha%20Franklin/The%20Queen%20of%20Soul/medium&path=%2Fmnt%2FNAS%2FServidor-Salita%2F4_Aretha%20Franklin%20-2014-%20The%20Queen%20of%20Soul%204%20(1967-1976)%5B24bit_192kHz%5D(AcousticSounds)(flac')%2F4-13%20I'm%20in%20Love%20-%20('Let%20Me%20in%20Your%20Life').flac&metadata=false Jun 05 16:17:29 volumio volumio[1039]: info: URI /mnt/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-13 I'm in Love - ('Let Me in Your Life').flac Jun 05 16:17:29 volumio volumio[1039]: info: Exploding uri music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-14 Ain't Nothing Like the Real Thing - ('Let Me in Your Life').flac in service mpd Jun 05 16:17:29 volumio volumio[1039]: info: ALBUMART /albumart?cacheid=902&web=Aretha%20Franklin/The%20Queen%20of%20Soul/medium&path=%2Fmnt%2FNAS%2FServidor-Salita%2F4_Aretha%20Franklin%20-2014-%20The%20Queen%20of%20Soul%204%20(1967-1976)%5B24bit_192kHz%5D(AcousticSounds)(flac')%2F4-14%20Ain't%20Nothing%20Like%20the%20Real%20Thing%20-%20('Let%20Me%20in%20Your%20Life').flac&metadata=false Jun 05 16:17:29 volumio volumio[1039]: info: URI /mnt/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-14 Ain't Nothing Like the Real Thing - ('Let Me in Your Life').flac Jun 05 16:17:29 volumio volumio[1039]: info: Exploding uri music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-15 Until You Come Back to Me (That's What I'm Gonna Do) - ('Let Me in Your Life').flac in service mpd Jun 05 16:17:29 volumio volumio[1039]: info: ALBUMART /albumart?cacheid=902&web=Aretha%20Franklin/The%20Queen%20of%20Soul/medium&path=%2Fmnt%2FNAS%2FServidor-Salita%2F4_Aretha%20Franklin%20-2014-%20The%20Queen%20of%20Soul%204%20(1967-1976)%5B24bit_192kHz%5D(AcousticSounds)(flac')%2F4-15%20Until%20You%20Come%20Back%20to%20Me%20(That's%20What%20I'm%20Gonna%20Do)%20-%20('Let%20Me%20in%20Your%20Life').flac&metadata=false Jun 05 16:17:29 volumio volumio[1039]: info: URI /mnt/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-15 Until You Come Back to Me (That's What I'm Gonna Do) - ('Let Me in Your Life').flac Jun 05 16:17:30 volumio volumio[1039]: info: Exploding uri music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-16 Look into Your Heart - ('Sparkle').flac in service mpd Jun 05 16:17:30 volumio volumio[1039]: info: ALBUMART /albumart?cacheid=902&web=Aretha%20Franklin/The%20Queen%20of%20Soul/medium&path=%2Fmnt%2FNAS%2FServidor-Salita%2F4_Aretha%20Franklin%20-2014-%20The%20Queen%20of%20Soul%204%20(1967-1976)%5B24bit_192kHz%5D(AcousticSounds)(flac')%2F4-16%20Look%20into%20Your%20Heart%20-%20('Sparkle').flac&metadata=false Jun 05 16:17:30 volumio volumio[1039]: info: URI /mnt/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-16 Look into Your Heart - ('Sparkle').flac Jun 05 16:17:30 volumio volumio[1039]: info: Exploding uri music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-17 Sparkle - ('Sparkle').flac in service mpd Jun 05 16:17:30 volumio volumio[1039]: info: ALBUMART /albumart?cacheid=902&web=Aretha%20Franklin/The%20Queen%20of%20Soul/medium&path=%2Fmnt%2FNAS%2FServidor-Salita%2F4_Aretha%20Franklin%20-2014-%20The%20Queen%20of%20Soul%204%20(1967-1976)%5B24bit_192kHz%5D(AcousticSounds)(flac')%2F4-17%20Sparkle%20-%20('Sparkle').flac&metadata=false Jun 05 16:17:30 volumio volumio[1039]: info: URI /mnt/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-17 Sparkle - ('Sparkle').flac Jun 05 16:17:30 volumio volumio[1039]: info: Exploding uri music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-18 Something He Can Feel - ('Sparkle').flac in service mpd Jun 05 16:17:30 volumio volumio[1039]: info: ALBUMART /albumart?cacheid=902&web=Aretha%20Franklin/The%20Queen%20of%20Soul/medium&path=%2Fmnt%2FNAS%2FServidor-Salita%2F4_Aretha%20Franklin%20-2014-%20The%20Queen%20of%20Soul%204%20(1967-1976)%5B24bit_192kHz%5D(AcousticSounds)(flac')%2F4-18%20Something%20He%20Can%20Feel%20-%20('Sparkle').flac&metadata=false Jun 05 16:17:30 volumio volumio[1039]: info: URI /mnt/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-18 Something He Can Feel - ('Sparkle').flac Jun 05 16:17:34 volumio volumio[1039]: info: Preload queue cleared Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::ClearQueue Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::stop Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::stPlaybackTimer Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::updateTrackBlock Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrackBlock Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::serviceStop Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::serviceStop Jun 05 16:17:34 volumio volumio[1039]: info: [1749133054254] ControllerWebradio::stop Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand stop Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::clearPlayQueue Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::saveQueue Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushQueue Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::addQueueItems Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::addQueueItems Jun 05 16:17:34 volumio volumio[1039]: info: Preload queue cleared Jun 05 16:17:34 volumio volumio[1039]: info: Adding Item to queue: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-01 Rock Steady - ('Young, Gifted and Black').flac Jun 05 16:17:34 volumio volumio[1039]: info: Using cached record of: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-01 Rock Steady - ('Young, Gifted and Black').flac Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushQueue Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::saveQueue Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::updateTrackBlock Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrackBlock Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPlay Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::play index 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::addQueueItems Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::addQueueItems Jun 05 16:17:34 volumio volumio[1039]: info: Preload queue cleared Jun 05 16:17:34 volumio volumio[1039]: info: Adding Item to queue: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-02 Young, Gifted and Black - ('Young, Gifted and Black').flac Jun 05 16:17:34 volumio volumio[1039]: info: Using cached record of: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-02 Young, Gifted and Black - ('Young, Gifted and Black').flac Jun 05 16:17:34 volumio volumio[1039]: info: Adding Item to queue: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-03 All the King's Horses - ('Young, Gifted and Black').flac Jun 05 16:17:34 volumio volumio[1039]: info: Using cached record of: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-03 All the King's Horses - ('Young, Gifted and Black').flac Jun 05 16:17:34 volumio volumio[1039]: info: Adding Item to queue: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-04 Oh Me Oh My (I'm a Fool for You Baby) - ('Young, Gifted and Black').flac Jun 05 16:17:34 volumio volumio[1039]: info: Using cached record of: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-04 Oh Me Oh My (I'm a Fool for You Baby) - ('Young, Gifted and Black').flac Jun 05 16:17:34 volumio volumio[1039]: info: Adding Item to queue: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-05 Day Dreaming - ('Young, Gifted and Black').flac Jun 05 16:17:34 volumio volumio[1039]: info: Using cached record of: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-05 Day Dreaming - ('Young, Gifted and Black').flac Jun 05 16:17:34 volumio volumio[1039]: info: Adding Item to queue: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-06 Mary, Don't You Weep - (Live at New Temple Missionary Baptist Church, Los Angeles, January 14, 1972).flac Jun 05 16:17:34 volumio volumio[1039]: info: Using cached record of: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-06 Mary, Don't You Weep - (Live at New Temple Missionary Baptist Church, Los Angeles, January 14, 1972).flac Jun 05 16:17:34 volumio volumio[1039]: info: Adding Item to queue: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-07 Climbing Higher Mountains - (Live at New Temple Missionary Baptist Church, Los Angeles, January 14, 1972).flac Jun 05 16:17:34 volumio volumio[1039]: info: Using cached record of: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-07 Climbing Higher Mountains - (Live at New Temple Missionary Baptist Church, Los Angeles, January 14, 1972).flac Jun 05 16:17:34 volumio volumio[1039]: info: Adding Item to queue: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-08 Precious Memories - (Live at New Temple Missionary Baptist Church, Los Angeles, January 14, 1972).flac Jun 05 16:17:34 volumio volumio[1039]: info: Using cached record of: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-08 Precious Memories - (Live at New Temple Missionary Baptist Church, Los Angeles, January 14, 1972).flac Jun 05 16:17:34 volumio volumio[1039]: info: Adding Item to queue: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-09 Master of Eyes (The Deepness of Your Eyes) - ('Hey Now Hey (The Other Side of the Sky)').flac Jun 05 16:17:34 volumio volumio[1039]: info: Using cached record of: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-09 Master of Eyes (The Deepness of Your Eyes) - ('Hey Now Hey (The Other Side of the Sky)').flac Jun 05 16:17:34 volumio volumio[1039]: info: Adding Item to queue: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-10 Angel - ('Hey Now Hey (The Other Side of the Sky)').flac Jun 05 16:17:34 volumio volumio[1039]: info: Using cached record of: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-10 Angel - ('Hey Now Hey (The Other Side of the Sky)').flac Jun 05 16:17:34 volumio volumio[1039]: info: Adding Item to queue: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-11 Somewhere - ('Hey Now Hey (The Other Side of the Sky)').flac Jun 05 16:17:34 volumio volumio[1039]: info: Using cached record of: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-11 Somewhere - ('Hey Now Hey (The Other Side of the Sky)').flac Jun 05 16:17:34 volumio volumio[1039]: info: Adding Item to queue: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-12 So Swell When You're Well - ('Hey Now Hey (The Other Side of the Sky)').flac Jun 05 16:17:34 volumio volumio[1039]: info: Using cached record of: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-12 So Swell When You're Well - ('Hey Now Hey (The Other Side of the Sky)').flac Jun 05 16:17:34 volumio volumio[1039]: info: Adding Item to queue: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-13 I'm in Love - ('Let Me in Your Life').flac Jun 05 16:17:34 volumio volumio[1039]: info: Using cached record of: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-13 I'm in Love - ('Let Me in Your Life').flac Jun 05 16:17:34 volumio volumio[1039]: info: Adding Item to queue: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-14 Ain't Nothing Like the Real Thing - ('Let Me in Your Life').flac Jun 05 16:17:34 volumio volumio[1039]: info: Using cached record of: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-14 Ain't Nothing Like the Real Thing - ('Let Me in Your Life').flac Jun 05 16:17:34 volumio volumio[1039]: info: Adding Item to queue: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-15 Until You Come Back to Me (That's What I'm Gonna Do) - ('Let Me in Your Life').flac Jun 05 16:17:34 volumio volumio[1039]: info: Using cached record of: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-15 Until You Come Back to Me (That's What I'm Gonna Do) - ('Let Me in Your Life').flac Jun 05 16:17:34 volumio volumio[1039]: info: Adding Item to queue: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-16 Look into Your Heart - ('Sparkle').flac Jun 05 16:17:34 volumio volumio[1039]: info: Using cached record of: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-16 Look into Your Heart - ('Sparkle').flac Jun 05 16:17:34 volumio volumio[1039]: info: Adding Item to queue: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-17 Sparkle - ('Sparkle').flac Jun 05 16:17:34 volumio volumio[1039]: info: Using cached record of: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-17 Sparkle - ('Sparkle').flac Jun 05 16:17:34 volumio volumio[1039]: info: Adding Item to queue: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-18 Something He Can Feel - ('Sparkle').flac Jun 05 16:17:34 volumio volumio[1039]: info: Using cached record of: music-library/NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-18 Something He Can Feel - ('Sparkle').flac Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::stop Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushQueue Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::saveQueue Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::play index undefined Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::updateTrackBlock Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrackBlock Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::startPlaybackTimer Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::clearAddPlayTracks NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-01 Rock Steady - ('Young, Gifted and Black').flac Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand stop Jun 05 16:17:34 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:34 volumio volumio[1039]: info: Jun 05 16:17:34 volumio volumio[1039]: ---------------------------- MPD announces state update: player Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand stop took 30 milliseconds Jun 05 16:17:34 volumio volumio[1039]: info: ControllerMpd::getState Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand stop took 6 milliseconds Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand clear Jun 05 16:17:34 volumio volumio[1039]: info: Jun 05 16:17:34 volumio volumio[1039]: ---------------------------- MPD announces state update: player Jun 05 16:17:34 volumio volumio[1039]: info: ControllerMpd::getState Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:17:34 volumio volumio[1039]: info: Jun 05 16:17:34 volumio volumio[1039]: ---------------------------- MPD announces state update: player Jun 05 16:17:34 volumio volumio[1039]: info: ControllerMpd::getState Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:17:34 volumio volumio[1039]: info: Jun 05 16:17:34 volumio volumio[1039]: ---------------------------- MPD announces system playlist update Jun 05 16:17:34 volumio volumio[1039]: info: Ignoring MPD Status Update Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand status took 7 milliseconds Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand clear took 6 milliseconds Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand status took 3 milliseconds Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand status took 2 milliseconds Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand add "NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-01 Rock Steady - ('Young, Gifted and Black').flac" Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:17:34 volumio volumio[1039]: info: ControllerMpd::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::servicePushState Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jun 05 16:17:34 volumio volumio[1039]: verbose: CURRENT POSITION 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::syncState stateService stop Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::syncState currentStatus stop Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:34 volumio volumio[1039]: info: No code Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:34 volumio volumio[1039]: info: ControllerMpd::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::servicePushState Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jun 05 16:17:34 volumio volumio[1039]: verbose: CURRENT POSITION 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::syncState stateService stop Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::syncState currentStatus stop Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:34 volumio volumio[1039]: info: No code Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:34 volumio volumio[1039]: info: ------------------------------ 26ms Jun 05 16:17:34 volumio volumio[1039]: info: ------------------------------ 26ms Jun 05 16:17:34 volumio volumio[1039]: info: Jun 05 16:17:34 volumio volumio[1039]: ---------------------------- MPD announces system playlist update Jun 05 16:17:34 volumio volumio[1039]: info: Ignoring MPD Status Update Jun 05 16:17:34 volumio volumio[1039]: info: Jun 05 16:17:34 volumio volumio[1039]: ---------------------------- MPD announces system playlist update Jun 05 16:17:34 volumio volumio[1039]: info: Ignoring MPD Status Update Jun 05 16:17:34 volumio volumio[1039]: error: updateQueue error: null Jun 05 16:17:34 volumio volumio[1039]: info: Jun 05 16:17:34 volumio volumio[1039]: ---------------------------- MPD announces system playlist update Jun 05 16:17:34 volumio volumio[1039]: info: Ignoring MPD Status Update Jun 05 16:17:34 volumio volumio[1039]: info: ------------------------------ 31ms Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand playlistinfo took 30 milliseconds Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand add "NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-01 Rock Steady - ('Young, Gifted and Black').flac" took 30 milliseconds Jun 05 16:17:34 volumio volumio[1039]: info: ------------------------------ 7ms Jun 05 16:17:34 volumio volumio[1039]: info: ------------------------------ 6ms Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::parseTrackInfo Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand play Jun 05 16:17:34 volumio volumio[1039]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jun 05 16:17:34 volumio volumio[1039]: info: ------------------------------ 40ms Jun 05 16:17:34 volumio volumio[1039]: info: Jun 05 16:17:34 volumio volumio[1039]: ---------------------------- MPD announces system playlist update Jun 05 16:17:34 volumio volumio[1039]: info: Ignoring MPD Status Update Jun 05 16:17:34 volumio volumio[1039]: info: Jun 05 16:17:34 volumio volumio[1039]: ---------------------------- MPD announces system playlist update Jun 05 16:17:34 volumio volumio[1039]: info: Ignoring MPD Status Update Jun 05 16:17:34 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:34 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:34 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:34 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:34 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:34 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:34 volumio volumio[1039]: info: ------------------------------ 24ms Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand play took 23 milliseconds Jun 05 16:17:34 volumio volumio[1039]: info: ------------------------------ 22ms Jun 05 16:17:34 volumio volumio[1039]: info: ------------------------------ 16ms Jun 05 16:17:34 volumio volumio[1039]: info: Jun 05 16:17:34 volumio volumio[1039]: ---------------------------- MPD announces state update: player Jun 05 16:17:34 volumio volumio[1039]: info: ControllerMpd::getState Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:17:34 volumio volumio[1039]: info: Jun 05 16:17:34 volumio volumio[1039]: ---------------------------- MPD announces state update: player Jun 05 16:17:34 volumio volumio[1039]: info: ControllerMpd::getState Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:17:34 volumio volumio[1039]: info: Jun 05 16:17:34 volumio volumio[1039]: ---------------------------- MPD announces state update: player Jun 05 16:17:34 volumio volumio[1039]: info: ControllerMpd::getState Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:17:34 volumio volumio[1039]: info: Jun 05 16:17:34 volumio volumio[1039]: ---------------------------- MPD announces state update: player Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand status took 34 milliseconds Jun 05 16:17:34 volumio volumio[1039]: info: ControllerMpd::getState Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand status took 34 milliseconds Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand status took 33 milliseconds Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 16:17:34 volumio volumio[1039]: info: Jun 05 16:17:34 volumio volumio[1039]: ---------------------------- MPD announces state update: player Jun 05 16:17:34 volumio volumio[1039]: info: ControllerMpd::getState Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:17:34 volumio volumio[1039]: info: Jun 05 16:17:34 volumio volumio[1039]: ---------------------------- MPD announces state update: player Jun 05 16:17:34 volumio volumio[1039]: info: ControllerMpd::getState Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand status Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand status took 6 milliseconds Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand playlistinfo took 6 milliseconds Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand playlistinfo took 6 milliseconds Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand playlistinfo took 6 milliseconds Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand status took 4 milliseconds Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand status took 3 milliseconds Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::parseTrackInfo Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::parseTrackInfo Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::parseTrackInfo Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::parseState Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 16:17:34 volumio volumio[1039]: info: ControllerMpd::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::servicePushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":195,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Rock Steady - ('Young, Gifted and Black')","artist":"Aretha Franklin","album":"The Queen of Soul","uri":"NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-01 Rock Steady - ('Young, Gifted and Black').flac","trackType":"flac"} Jun 05 16:17:34 volumio volumio[1039]: verbose: CURRENT POSITION 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::syncState stateService play Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::syncState currentStatus stop Jun 05 16:17:34 volumio volumio[1039]: info: ControllerMpd::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::servicePushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":195,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Rock Steady - ('Young, Gifted and Black')","artist":"Aretha Franklin","album":"The Queen of Soul","uri":"NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-01 Rock Steady - ('Young, Gifted and Black').flac","trackType":"flac"} Jun 05 16:17:34 volumio volumio[1039]: verbose: CURRENT POSITION 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::syncState stateService play Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::syncState currentStatus play Jun 05 16:17:34 volumio volumio[1039]: info: Received an update from plugin. extracting info from payload Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:34 volumio volumio[1039]: info: ControllerMpd::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::servicePushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":195,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Rock Steady - ('Young, Gifted and Black')","artist":"Aretha Franklin","album":"The Queen of Soul","uri":"NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-01 Rock Steady - ('Young, Gifted and Black').flac","trackType":"flac"} Jun 05 16:17:34 volumio volumio[1039]: verbose: CURRENT POSITION 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::syncState stateService play Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::syncState currentStatus play Jun 05 16:17:34 volumio volumio[1039]: info: Received an update from plugin. extracting info from payload Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:34 volumio volumio[1039]: info: ------------------------------ 54ms Jun 05 16:17:34 volumio volumio[1039]: info: ------------------------------ 59ms Jun 05 16:17:34 volumio volumio[1039]: info: ------------------------------ 58ms Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand playlistinfo took 19 milliseconds Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand playlistinfo took 18 milliseconds Jun 05 16:17:34 volumio volumio[1039]: info: sendMpdCommand playlistinfo took 18 milliseconds Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::parseTrackInfo Jun 05 16:17:34 volumio volumio[1039]: verbose: ControllerMpd::parseTrackInfo Jun 05 16:17:34 volumio volumio[1039]: info: ControllerMpd::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::servicePushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":195,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Rock Steady - ('Young, Gifted and Black')","artist":"Aretha Franklin","album":"The Queen of Soul","uri":"NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-01 Rock Steady - ('Young, Gifted and Black').flac","trackType":"flac"} Jun 05 16:17:34 volumio volumio[1039]: verbose: CURRENT POSITION 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::syncState stateService play Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::syncState currentStatus play Jun 05 16:17:34 volumio volumio[1039]: info: Received an update from plugin. extracting info from payload Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:34 volumio volumio[1039]: info: ControllerMpd::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::servicePushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":195,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Rock Steady - ('Young, Gifted and Black')","artist":"Aretha Franklin","album":"The Queen of Soul","uri":"NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-01 Rock Steady - ('Young, Gifted and Black').flac","trackType":"flac"} Jun 05 16:17:34 volumio volumio[1039]: verbose: CURRENT POSITION 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::syncState stateService play Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::syncState currentStatus play Jun 05 16:17:34 volumio volumio[1039]: info: Received an update from plugin. extracting info from payload Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:34 volumio volumio[1039]: info: ControllerMpd::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::servicePushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":195,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Rock Steady - ('Young, Gifted and Black')","artist":"Aretha Franklin","album":"The Queen of Soul","uri":"NAS/Servidor-Salita/4_Aretha Franklin -2014- The Queen of Soul 4 (1967-1976)[24bit_192kHz](AcousticSounds)(flac')/4-01 Rock Steady - ('Young, Gifted and Black').flac","trackType":"flac"} Jun 05 16:17:34 volumio volumio[1039]: verbose: CURRENT POSITION 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::syncState stateService play Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::syncState currentStatus play Jun 05 16:17:34 volumio volumio[1039]: info: Received an update from plugin. extracting info from payload Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:34 volumio volumio[1039]: info: CoreStateMachine::pushState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Jun 05 16:17:34 volumio volumio[1039]: info: ------------------------------ 52ms Jun 05 16:17:34 volumio volumio[1039]: info: ------------------------------ 50ms Jun 05 16:17:34 volumio volumio[1039]: info: ------------------------------ 50ms Jun 05 16:17:34 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:34 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:34 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:34 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:34 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:34 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 05 16:17:34 volumio volumio[1039]: info: Discovery: Getting this device information Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::volumioGetState Jun 05 16:17:34 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Jun 05 16:17:34 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 05 16:17:43 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 05 16:17:43 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 05 16:17:51 volumio volumio[1039]: info: Enabling plugin fusiondsp Jun 05 16:17:51 volumio volumio[1039]: info: Loading plugin "fusiondsp"... Jun 05 16:17:52 volumio volumio[1039]: info: Applying required configuration parameters for plugin fusiondsp Jun 05 16:17:52 volumio volumio[1039]: info: Preparing to generate the ALSA configuration file Jun 05 16:17:52 volumio volumio[1039]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jun 05 16:17:52 volumio volumio[1039]: info: Reading ALSA contributions from plugins. Jun 05 16:17:52 volumio volumio[1039]: info: Asound.conf file written Jun 05 16:17:52 volumio sudo[7376]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jun 05 16:17:52 volumio sudo[7376]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 16:17:52 volumio sudo[7376]: pam_unix(sudo:session): session closed for user root Jun 05 16:17:52 volumio volumio[1039]: info: Output device has changed, restarting MPD Jun 05 16:17:52 volumio sudo[7381]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 05 16:17:52 volumio sudo[7381]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 16:17:52 volumio sudo[7381]: pam_unix(sudo:session): session closed for user root Jun 05 16:17:52 volumio volumio[1039]: info: Output device has changed, restarting Shairport Sync Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 05 16:17:52 volumio sudo[7384]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 05 16:17:52 volumio sudo[7384]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 16:17:52 volumio systemd[1]: Stopping Music Player Daemon... Jun 05 16:17:52 volumio volumio[1039]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 05 16:17:52 volumio volumio[1039]: info: PLUGIN START: fusiondsp Jun 05 16:17:52 volumio volumio[1039]: info: Loading i18n strings for locale es Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 16:17:52 volumio volumio[1039]: info: FusionDsp - mixtype--------------------- Hardware Jun 05 16:17:52 volumio volumio[1039]: info: Preparing to generate the ALSA configuration file Jun 05 16:17:52 volumio volumio[1039]: info: Done. Jun 05 16:17:52 volumio systemd[1]: mpd.service: Succeeded. Jun 05 16:17:52 volumio systemd[1]: Stopped Music Player Daemon. Jun 05 16:17:52 volumio volumio[1039]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jun 05 16:17:52 volumio volumio[1039]: info: Reading ALSA contributions from plugins. Jun 05 16:17:52 volumio volumio[1039]: error: Upnp client error: Error: This socket has been ended by the other party Jun 05 16:17:52 volumio volumio[1039]: info: MPD Permissions set Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 16:17:52 volumio volumio[1039]: info: Starting Shairport Sync Jun 05 16:17:52 volumio volumio[1039]: info: Asound.conf file unchanged, so no further update is needed Jun 05 16:17:52 volumio volumio[1039]: info: Output device has changed, restarting MPD Jun 05 16:17:52 volumio sudo[7397]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 05 16:17:52 volumio sudo[7397]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 16:17:52 volumio systemd[1]: Starting Music Player Daemon... Jun 05 16:17:52 volumio volumio[1039]: info: Output device has changed, restarting Shairport Sync Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 05 16:17:52 volumio sudo[7400]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 05 16:17:52 volumio sudo[7400]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 16:17:52 volumio sudo[7400]: pam_unix(sudo:session): session closed for user root Jun 05 16:17:52 volumio sudo[7403]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 05 16:17:52 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 05 16:17:52 volumio sudo[7403]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 16:17:52 volumio systemd[1]: shairport-sync.service: Succeeded. Jun 05 16:17:52 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 05 16:17:52 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 05 16:17:52 volumio sudo[7397]: pam_unix(sudo:session): session closed for user root Jun 05 16:17:52 volumio volumio[1039]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 05 16:17:52 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jun 05 16:17:52 volumio systemd[1]: mpd.service: Succeeded. Jun 05 16:17:52 volumio systemd[1]: Stopped Music Player Daemon. Jun 05 16:17:52 volumio volumio[1039]: info: MPD Permissions set Jun 05 16:17:52 volumio volumio[1039]: info: Shairport-Sync Started Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 16:17:52 volumio systemd[1]: Starting Music Player Daemon... Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 05 16:17:52 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 16:17:52 volumio volumio[1039]: info: Starting Shairport Sync Jun 05 16:17:52 volumio sudo[7417]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 05 16:17:52 volumio sudo[7417]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 16:17:52 volumio sudo[7409]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 05 16:17:52 volumio sudo[7409]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 16:17:52 volumio sudo[7409]: pam_unix(sudo:session): session closed for user root Jun 05 16:17:52 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 05 16:17:52 volumio systemd[1]: shairport-sync.service: Succeeded. Jun 05 16:17:52 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 05 16:17:52 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 05 16:17:52 volumio sudo[7417]: pam_unix(sudo:session): session closed for user root Jun 05 16:17:52 volumio volumio[1039]: info: Shairport-Sync Started Jun 05 16:17:53 volumio mpd[7420]: Jun 05 16:17 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 05 16:17:53 volumio systemd[1]: Started Music Player Daemon. Jun 05 16:17:53 volumio sudo[7403]: pam_unix(sudo:session): session closed for user root Jun 05 16:17:53 volumio sudo[7384]: pam_unix(sudo:session): session closed for user root Jun 05 16:17:53 volumio volumio[1039]: error: MPD error: The expression evaluated to a falsy value: Jun 05 16:17:53 volumio volumio[1039]: assert.ok(self.idling) Jun 05 16:17:53 volumio volumio[1039]: error: The expression evaluated to a falsy value: Jun 05 16:17:53 volumio volumio[1039]: assert.ok(self.idling) Jun 05 16:17:53 volumio volumio[1039]: error: updateQueue error: null Jun 05 16:17:54 volumio volumio[1039]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 05 16:17:54 volumio volumio[1039]: TypeError: Cannot read property 'off' of undefined Jun 05 16:17:54 volumio volumio[1039]: at FusionDsp.onStop (/data/plugins/audio_interface/fusiondsp/index.js:107:15) Jun 05 16:17:54 volumio volumio[1039]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Jun 05 16:17:54 volumio volumio[1039]: at PluginManager.disableAndStopPlugin (/volumio/app/pluginmanager.js:1883:8) Jun 05 16:17:54 volumio volumio[1039]: at CoreCommandRouter.disableAndStopPlugin (/volumio/app/index.js:1551:29) Jun 05 16:17:54 volumio volumio[1039]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1395:47) Jun 05 16:17:54 volumio volumio[1039]: at Socket.emit (events.js:315:20) Jun 05 16:17:54 volumio volumio[1039]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jun 05 16:17:54 volumio volumio[1039]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Jun 05 16:17:54 volumio volumio[1039]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 05 16:17:54 volumio sudo[7436]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-05 16:16 Jun 05 16:17:54 volumio sudo[7436]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"