-- Logs begin at Sun 2024-01-28 08:24:14 GMT, end at Sun 2024-01-28 09:49:56 GMT. -- Jan 28 09:48:00 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:00 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:48:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699502. Jan 28 09:48:02 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:48:02 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:48:02 volumio go-librespot[4006]: Librespot-go daemon starting... Jan 28 09:48:02 volumio go-librespot[4006]: time="2024-01-28T09:48:02Z" level=info msg="generated new device id: 5a825062a61cdaa0f1493bf3d46e1855633e4977" Jan 28 09:48:03 volumio go-librespot[4006]: time="2024-01-28T09:48:03Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:48:02Z is before 2025-12-08T00:00:00Z" Jan 28 09:48:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:48:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:48:03 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:03 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:48:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699503. Jan 28 09:48:06 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:48:06 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:48:06 volumio go-librespot[4021]: Librespot-go daemon starting... Jan 28 09:48:06 volumio go-librespot[4021]: time="2024-01-28T09:48:06Z" level=info msg="generated new device id: 4812eb43423aa8e27f8a1865397ba958ca9c8783" Jan 28 09:48:06 volumio go-librespot[4021]: time="2024-01-28T09:48:06Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:48:06Z is before 2025-12-08T00:00:00Z" Jan 28 09:48:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:48:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:48:06 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:06 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:48:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699504. Jan 28 09:48:09 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:48:09 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:48:09 volumio go-librespot[4046]: Librespot-go daemon starting... Jan 28 09:48:09 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:09 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:09 volumio go-librespot[4046]: time="2024-01-28T09:48:09Z" level=info msg="generated new device id: 6a310dff68dd80acdafd541a622528bf42c8d1da" Jan 28 09:48:09 volumio go-librespot[4046]: time="2024-01-28T09:48:09Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:48:09Z is before 2025-12-08T00:00:00Z" Jan 28 09:48:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:48:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:48:12 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:12 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:48:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699505. Jan 28 09:48:12 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:48:12 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:48:12 volumio go-librespot[4112]: Librespot-go daemon starting... Jan 28 09:48:12 volumio go-librespot[4112]: time="2024-01-28T09:48:12Z" level=info msg="generated new device id: 86282124ba24c7d80cb826b8fd690e735ce66f07" Jan 28 09:48:13 volumio go-librespot[4112]: time="2024-01-28T09:48:13Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:48:12Z is before 2025-12-08T00:00:00Z" Jan 28 09:48:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:48:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:48:15 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:15 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:48:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699506. Jan 28 09:48:16 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:48:16 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:48:16 volumio go-librespot[4126]: Librespot-go daemon starting... Jan 28 09:48:16 volumio go-librespot[4126]: time="2024-01-28T09:48:16Z" level=info msg="generated new device id: 39e11b1d929927b058632f08bc65ad4ab44b2f37" Jan 28 09:48:16 volumio go-librespot[4126]: time="2024-01-28T09:48:16Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:48:16Z is before 2025-12-08T00:00:00Z" Jan 28 09:48:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:48:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:48:18 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:18 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:19 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:48:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699507. Jan 28 09:48:19 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:48:19 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:48:19 volumio go-librespot[4153]: Librespot-go daemon starting... Jan 28 09:48:19 volumio go-librespot[4153]: time="2024-01-28T09:48:19Z" level=info msg="generated new device id: de29915dfa50635d39ec834f3c556f50d7d29876" Jan 28 09:48:19 volumio go-librespot[4153]: time="2024-01-28T09:48:19Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:48:19Z is before 2025-12-08T00:00:00Z" Jan 28 09:48:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:48:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:48:21 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:21 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:48:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699508. Jan 28 09:48:22 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:48:22 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:48:22 volumio go-librespot[4184]: Librespot-go daemon starting... Jan 28 09:48:22 volumio go-librespot[4184]: time="2024-01-28T09:48:22Z" level=info msg="generated new device id: 6e66affd6e2b51d6af6fab78ed6bd7671ddbbca7" Jan 28 09:48:23 volumio go-librespot[4184]: time="2024-01-28T09:48:23Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:48:22Z is before 2025-12-08T00:00:00Z" Jan 28 09:48:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:48:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:48:24 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:24 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:48:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699509. Jan 28 09:48:26 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:48:26 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:48:26 volumio go-librespot[4199]: Librespot-go daemon starting... Jan 28 09:48:26 volumio go-librespot[4199]: time="2024-01-28T09:48:26Z" level=info msg="generated new device id: d95fa6a900cf66b11a10e79c89d258db87114cfd" Jan 28 09:48:26 volumio go-librespot[4199]: time="2024-01-28T09:48:26Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:48:26Z is before 2025-12-08T00:00:00Z" Jan 28 09:48:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:48:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:48:27 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:27 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:29 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:48:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699510. Jan 28 09:48:29 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:48:29 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:48:29 volumio go-librespot[4224]: Librespot-go daemon starting... Jan 28 09:48:29 volumio go-librespot[4224]: time="2024-01-28T09:48:29Z" level=info msg="generated new device id: 25f7f5078e0ff43bf885881df0f4a24e6afaa5af" Jan 28 09:48:29 volumio go-librespot[4224]: time="2024-01-28T09:48:29Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:48:29Z is before 2025-12-08T00:00:00Z" Jan 28 09:48:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:48:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:48:30 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:30 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:48:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699511. Jan 28 09:48:33 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:48:33 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:48:33 volumio go-librespot[4254]: Librespot-go daemon starting... Jan 28 09:48:33 volumio go-librespot[4254]: time="2024-01-28T09:48:33Z" level=info msg="generated new device id: 47ab2bf27960d38266e0c554d36fac7b4d2a763d" Jan 28 09:48:33 volumio go-librespot[4254]: time="2024-01-28T09:48:33Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:48:33Z is before 2025-12-08T00:00:00Z" Jan 28 09:48:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:48:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:48:33 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:33 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:36 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:36 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:48:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699512. Jan 28 09:48:36 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:48:36 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:48:36 volumio go-librespot[4269]: Librespot-go daemon starting... Jan 28 09:48:36 volumio go-librespot[4269]: time="2024-01-28T09:48:36Z" level=info msg="generated new device id: bdb8c2d834e291b9943593a84b834e70b1d5cc96" Jan 28 09:48:36 volumio go-librespot[4269]: time="2024-01-28T09:48:36Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:48:36Z is before 2025-12-08T00:00:00Z" Jan 28 09:48:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:48:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:48:39 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:39 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:48:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699513. Jan 28 09:48:40 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:48:40 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:48:40 volumio go-librespot[4310]: Librespot-go daemon starting... Jan 28 09:48:40 volumio go-librespot[4310]: time="2024-01-28T09:48:40Z" level=info msg="generated new device id: 3051dc73ccfcdc66d566e052cb30f97f42777af1" Jan 28 09:48:40 volumio go-librespot[4310]: time="2024-01-28T09:48:40Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:48:40Z is before 2025-12-08T00:00:00Z" Jan 28 09:48:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:48:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:48:42 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:42 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:43 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:48:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699514. Jan 28 09:48:43 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:48:43 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:48:43 volumio go-librespot[4327]: Librespot-go daemon starting... Jan 28 09:48:43 volumio go-librespot[4327]: time="2024-01-28T09:48:43Z" level=info msg="generated new device id: 5ce49f19b06e544eea87f0bbd7b17cb0c1ff5683" Jan 28 09:48:43 volumio go-librespot[4327]: time="2024-01-28T09:48:43Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:48:43Z is before 2025-12-08T00:00:00Z" Jan 28 09:48:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:48:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:48:45 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:45 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:47 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:48:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699515. Jan 28 09:48:47 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:48:47 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:48:47 volumio go-librespot[4343]: Librespot-go daemon starting... Jan 28 09:48:47 volumio go-librespot[4343]: time="2024-01-28T09:48:47Z" level=info msg="generated new device id: 9b17670cf12b26a73b8abb876d7926ce9b55fa17" Jan 28 09:48:47 volumio go-librespot[4343]: time="2024-01-28T09:48:47Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:48:47Z is before 2025-12-08T00:00:00Z" Jan 28 09:48:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:48:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:48:48 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:48 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:50 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:48:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699516. Jan 28 09:48:50 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:48:50 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:48:50 volumio go-librespot[4382]: Librespot-go daemon starting... Jan 28 09:48:50 volumio go-librespot[4382]: time="2024-01-28T09:48:50Z" level=info msg="generated new device id: 7aead7ec25914fac6f442eb4903de009e9e9c9a7" Jan 28 09:48:50 volumio go-librespot[4382]: time="2024-01-28T09:48:50Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:48:50Z is before 2025-12-08T00:00:00Z" Jan 28 09:48:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:48:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:48:51 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:51 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:54 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:48:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699517. Jan 28 09:48:54 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:48:54 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:48:54 volumio go-librespot[4396]: Librespot-go daemon starting... Jan 28 09:48:54 volumio go-librespot[4396]: time="2024-01-28T09:48:54Z" level=info msg="generated new device id: c6a3a97dd831c5846877cd6bbd8c27ed8eed804a" Jan 28 09:48:54 volumio go-librespot[4396]: time="2024-01-28T09:48:54Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:48:54Z is before 2025-12-08T00:00:00Z" Jan 28 09:48:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:48:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:48:54 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:54 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:57 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:48:57 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:48:57 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:48:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699518. Jan 28 09:48:57 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:48:57 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:48:57 volumio go-librespot[4423]: Librespot-go daemon starting... Jan 28 09:48:57 volumio go-librespot[4423]: time="2024-01-28T09:48:57Z" level=info msg="generated new device id: c134120e48db88f8320961f2ad84ffe5bf10f58a" Jan 28 09:48:57 volumio go-librespot[4423]: time="2024-01-28T09:48:57Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:48:57Z is before 2025-12-08T00:00:00Z" Jan 28 09:48:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:48:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:48:58 volumio volumio[813]: info: CorePlayQueue::getTrack 1 Jan 28 09:48:58 volumio volumio[813]: info: CorePlayQueue::getTrack 2 Jan 28 09:48:58 volumio volumio[813]: info: Prefetching next song Jan 28 09:48:58 volumio volumio[813]: info: DOING PREFETCH IN MPD Jan 28 09:48:58 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand add "USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 03. Don't Think Of Me.flac" Jan 28 09:48:58 volumio volumio[813]: info: Jan 28 09:48:58 volumio volumio[813]: ---------------------------- MPD announces system playlist update Jan 28 09:48:58 volumio volumio[813]: info: Ignoring MPD Status Update Jan 28 09:48:58 volumio volumio[813]: info: sendMpdCommand add "USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 03. Don't Think Of Me.flac" took 2 milliseconds Jan 28 09:48:58 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand consume 1 Jan 28 09:48:58 volumio volumio[813]: info: Jan 28 09:48:58 volumio volumio[813]: ---------------------------- MPD announces system playlist update Jan 28 09:48:58 volumio volumio[813]: info: Ignoring MPD Status Update Jan 28 09:48:58 volumio volumio[813]: info: Jan 28 09:48:58 volumio volumio[813]: ---------------------------- MPD announces system playlist update Jan 28 09:48:58 volumio volumio[813]: info: Ignoring MPD Status Update Jan 28 09:48:58 volumio volumio[813]: info: Jan 28 09:48:58 volumio volumio[813]: ---------------------------- MPD announces system playlist update Jan 28 09:48:58 volumio volumio[813]: info: Ignoring MPD Status Update Jan 28 09:48:58 volumio volumio[813]: info: ------------------------------ 5ms Jan 28 09:48:58 volumio volumio[813]: info: sendMpdCommand consume 1 took 4 milliseconds Jan 28 09:48:58 volumio volumio[813]: info: ------------------------------ 3ms Jan 28 09:48:58 volumio volumio[813]: info: ------------------------------ 2ms Jan 28 09:48:58 volumio volumio[813]: info: ------------------------------ 3ms Jan 28 09:49:00 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:49:00 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:49:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:49:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699519. Jan 28 09:49:01 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:49:01 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:49:01 volumio go-librespot[4456]: Librespot-go daemon starting... Jan 28 09:49:01 volumio go-librespot[4456]: time="2024-01-28T09:49:01Z" level=info msg="generated new device id: 981fbc2cd701e13c532e8032ba2b78ed4b13fbbd" Jan 28 09:49:01 volumio go-librespot[4456]: time="2024-01-28T09:49:01Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:49:01Z is before 2025-12-08T00:00:00Z" Jan 28 09:49:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:49:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:49:03 volumio volumio[813]: info: CoreStateMachine::startPlaybackTimer Jan 28 09:49:03 volumio volumio[813]: info: CorePlayQueue::getTrack 2 Jan 28 09:49:03 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:49:03 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:49:03 volumio volumio[813]: info: Jan 28 09:49:03 volumio volumio[813]: ---------------------------- MPD announces system playlist update Jan 28 09:49:03 volumio volumio[813]: info: Ignoring MPD Status Update Jan 28 09:49:03 volumio volumio[813]: info: Jan 28 09:49:03 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:03 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:03 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:03 volumio volumio[813]: info: ------------------------------ 2ms Jan 28 09:49:03 volumio volumio[813]: info: sendMpdCommand status took 1 milliseconds Jan 28 09:49:03 volumio volumio[813]: verbose: ControllerMpd::parseState Jan 28 09:49:03 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 09:49:03 volumio volumio[813]: info: Jan 28 09:49:03 volumio volumio[813]: ---------------------------- MPD announces system playlist update Jan 28 09:49:03 volumio volumio[813]: info: Ignoring MPD Status Update Jan 28 09:49:03 volumio volumio[813]: info: Jan 28 09:49:03 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:03 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:03 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:03 volumio volumio[813]: info: Jan 28 09:49:03 volumio volumio[813]: ---------------------------- MPD announces system playlist update Jan 28 09:49:03 volumio volumio[813]: info: Ignoring MPD Status Update Jan 28 09:49:03 volumio volumio[813]: info: Jan 28 09:49:03 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:03 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:03 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:03 volumio volumio[813]: info: Jan 28 09:49:03 volumio volumio[813]: ---------------------------- MPD announces system playlist update Jan 28 09:49:03 volumio volumio[813]: info: Ignoring MPD Status Update Jan 28 09:49:03 volumio volumio[813]: info: Jan 28 09:49:03 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:03 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:03 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:03 volumio volumio[813]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 28 09:49:03 volumio volumio[813]: info: ------------------------------ 6ms Jan 28 09:49:03 volumio volumio[813]: info: sendMpdCommand status took 5 milliseconds Jan 28 09:49:03 volumio volumio[813]: info: ------------------------------ 5ms Jan 28 09:49:03 volumio volumio[813]: info: sendMpdCommand status took 4 milliseconds Jan 28 09:49:03 volumio volumio[813]: info: ------------------------------ 3ms Jan 28 09:49:03 volumio volumio[813]: info: sendMpdCommand status took 3 milliseconds Jan 28 09:49:03 volumio volumio[813]: verbose: ControllerMpd::parseTrackInfo Jan 28 09:49:03 volumio volumio[813]: verbose: ControllerMpd::parseState Jan 28 09:49:03 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 09:49:03 volumio volumio[813]: verbose: ControllerMpd::parseState Jan 28 09:49:03 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 09:49:03 volumio volumio[813]: verbose: ControllerMpd::parseState Jan 28 09:49:03 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 09:49:03 volumio volumio[813]: info: ControllerMpd::pushState Jan 28 09:49:03 volumio volumio[813]: info: CoreCommandRouter::servicePushState Jan 28 09:49:03 volumio volumio[813]: info: CorePlayQueue::getTrack 2 Jan 28 09:49:03 volumio volumio[813]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":272,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1000 Kbps","isStreaming":false,"title":"Don't Think Of Me","artist":"Dido","album":"No Angel (Special Edition)","uri":"USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 03. Don't Think Of Me.flac","trackType":"flac"} Jan 28 09:49:03 volumio volumio[813]: verbose: CURRENT POSITION 2 Jan 28 09:49:03 volumio volumio[813]: info: CoreStateMachine::syncState stateService play Jan 28 09:49:03 volumio volumio[813]: info: CoreStateMachine::syncState currentStatus play Jan 28 09:49:03 volumio volumio[813]: info: Received an update from plugin. extracting info from payload Jan 28 09:49:03 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:03 volumio volumio[813]: info: CorePlayQueue::getTrack 2 Jan 28 09:49:03 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 09:49:03 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:03 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:03 volumio volumio[813]: info: CorePlayQueue::getTrack 2 Jan 28 09:49:03 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:03 volumio volumio[813]: info: ------------------------------ 16ms Jan 28 09:49:03 volumio volumio[813]: info: sendMpdCommand playlistinfo took 8 milliseconds Jan 28 09:49:03 volumio volumio[813]: info: sendMpdCommand playlistinfo took 8 milliseconds Jan 28 09:49:03 volumio volumio[813]: info: sendMpdCommand playlistinfo took 8 milliseconds Jan 28 09:49:03 volumio volumio[813]: verbose: ControllerMpd::parseTrackInfo Jan 28 09:49:03 volumio volumio[813]: verbose: ControllerMpd::parseTrackInfo Jan 28 09:49:03 volumio volumio[813]: verbose: ControllerMpd::parseTrackInfo Jan 28 09:49:03 volumio volumio[813]: info: ControllerMpd::pushState Jan 28 09:49:03 volumio volumio[813]: info: CoreCommandRouter::servicePushState Jan 28 09:49:03 volumio volumio[813]: info: CorePlayQueue::getTrack 2 Jan 28 09:49:03 volumio volumio[813]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":272,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1000 Kbps","isStreaming":false,"title":"Don't Think Of Me","artist":"Dido","album":"No Angel (Special Edition)","uri":"USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 03. Don't Think Of Me.flac","trackType":"flac"} Jan 28 09:49:03 volumio volumio[813]: verbose: CURRENT POSITION 2 Jan 28 09:49:03 volumio volumio[813]: info: CoreStateMachine::syncState stateService play Jan 28 09:49:03 volumio volumio[813]: info: CoreStateMachine::syncState currentStatus play Jan 28 09:49:03 volumio volumio[813]: info: Received an update from plugin. extracting info from payload Jan 28 09:49:03 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:03 volumio volumio[813]: info: CorePlayQueue::getTrack 2 Jan 28 09:49:03 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:03 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:03 volumio volumio[813]: info: CorePlayQueue::getTrack 2 Jan 28 09:49:03 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:03 volumio volumio[813]: info: ControllerMpd::pushState Jan 28 09:49:03 volumio volumio[813]: info: CoreCommandRouter::servicePushState Jan 28 09:49:03 volumio volumio[813]: info: CorePlayQueue::getTrack 2 Jan 28 09:49:03 volumio volumio[813]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":272,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1000 Kbps","isStreaming":false,"title":"Don't Think Of Me","artist":"Dido","album":"No Angel (Special Edition)","uri":"USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 03. Don't Think Of Me.flac","trackType":"flac"} Jan 28 09:49:03 volumio volumio[813]: verbose: CURRENT POSITION 2 Jan 28 09:49:03 volumio volumio[813]: info: CoreStateMachine::syncState stateService play Jan 28 09:49:03 volumio volumio[813]: info: CoreStateMachine::syncState currentStatus play Jan 28 09:49:03 volumio volumio[813]: info: Received an update from plugin. extracting info from payload Jan 28 09:49:03 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:03 volumio volumio[813]: info: CorePlayQueue::getTrack 2 Jan 28 09:49:03 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:03 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:03 volumio volumio[813]: info: CorePlayQueue::getTrack 2 Jan 28 09:49:03 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:03 volumio volumio[813]: info: ControllerMpd::pushState Jan 28 09:49:03 volumio volumio[813]: info: CoreCommandRouter::servicePushState Jan 28 09:49:03 volumio volumio[813]: info: CorePlayQueue::getTrack 2 Jan 28 09:49:03 volumio volumio[813]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":272,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1000 Kbps","isStreaming":false,"title":"Don't Think Of Me","artist":"Dido","album":"No Angel (Special Edition)","uri":"USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 03. Don't Think Of Me.flac","trackType":"flac"} Jan 28 09:49:03 volumio volumio[813]: verbose: CURRENT POSITION 2 Jan 28 09:49:03 volumio volumio[813]: info: CoreStateMachine::syncState stateService play Jan 28 09:49:03 volumio volumio[813]: info: CoreStateMachine::syncState currentStatus play Jan 28 09:49:03 volumio volumio[813]: info: Received an update from plugin. extracting info from payload Jan 28 09:49:03 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:03 volumio volumio[813]: info: CorePlayQueue::getTrack 2 Jan 28 09:49:03 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:03 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:03 volumio volumio[813]: info: CorePlayQueue::getTrack 2 Jan 28 09:49:03 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:03 volumio volumio[813]: info: ------------------------------ 33ms Jan 28 09:49:03 volumio volumio[813]: info: ------------------------------ 31ms Jan 28 09:49:03 volumio volumio[813]: info: ------------------------------ 31ms Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:03 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:03 volumio volumio[813]: info: CorePlayQueue::getTrack 2 Jan 28 09:49:03 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:03 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:49:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699520. Jan 28 09:49:04 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:49:04 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:49:04 volumio go-librespot[4475]: Librespot-go daemon starting... Jan 28 09:49:04 volumio go-librespot[4475]: time="2024-01-28T09:49:04Z" level=info msg="generated new device id: 9dcee962f6d1f480b9751af834dac440cc13fcfb" Jan 28 09:49:04 volumio go-librespot[4475]: time="2024-01-28T09:49:04Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:49:04Z is before 2025-12-08T00:00:00Z" Jan 28 09:49:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:49:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:49:06 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:49:06 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:49:07 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:49:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699521. Jan 28 09:49:07 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:49:07 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:49:07 volumio go-librespot[4501]: Librespot-go daemon starting... Jan 28 09:49:07 volumio go-librespot[4501]: time="2024-01-28T09:49:07Z" level=info msg="generated new device id: b8a24b11b69edac40ff734ee4452e70aa71727f9" Jan 28 09:49:07 volumio go-librespot[4501]: time="2024-01-28T09:49:07Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:49:07Z is before 2025-12-08T00:00:00Z" Jan 28 09:49:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:49:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:49:09 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:49:09 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:49:11 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:49:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699522. Jan 28 09:49:11 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:49:11 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:49:11 volumio go-librespot[4529]: Librespot-go daemon starting... Jan 28 09:49:11 volumio go-librespot[4529]: time="2024-01-28T09:49:11Z" level=info msg="generated new device id: 71e188286b80ccbc7057e7cf8c1d6d8a87dcae24" Jan 28 09:49:11 volumio go-librespot[4529]: time="2024-01-28T09:49:11Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:49:11Z is before 2025-12-08T00:00:00Z" Jan 28 09:49:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:49:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:49:12 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:49:12 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:49:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:49:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699523. Jan 28 09:49:14 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:49:14 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:49:14 volumio go-librespot[4580]: Librespot-go daemon starting... Jan 28 09:49:14 volumio go-librespot[4580]: time="2024-01-28T09:49:14Z" level=info msg="generated new device id: d1dfe379dd753955d9ebeb33df8b644cffb7ceb6" Jan 28 09:49:14 volumio go-librespot[4580]: time="2024-01-28T09:49:14Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:49:14Z is before 2025-12-08T00:00:00Z" Jan 28 09:49:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:49:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:49:15 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:49:15 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:49:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:49:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699524. Jan 28 09:49:18 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:49:18 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:49:18 volumio go-librespot[4605]: Librespot-go daemon starting... Jan 28 09:49:18 volumio go-librespot[4605]: time="2024-01-28T09:49:18Z" level=info msg="generated new device id: ca3e3dc6c8dfb5fde01377c1061b66eb71d4ad7b" Jan 28 09:49:18 volumio go-librespot[4605]: time="2024-01-28T09:49:18Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:49:18Z is before 2025-12-08T00:00:00Z" Jan 28 09:49:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:49:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:49:18 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:49:18 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:49:21 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:49:21 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:49:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:49:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699525. Jan 28 09:49:21 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:49:21 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:49:21 volumio go-librespot[4638]: Librespot-go daemon starting... Jan 28 09:49:21 volumio go-librespot[4638]: time="2024-01-28T09:49:21Z" level=info msg="generated new device id: 0c6461c1d5b3e3f21f055994a4d5422b7a6b44ab" Jan 28 09:49:21 volumio go-librespot[4638]: time="2024-01-28T09:49:21Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:49:21Z is before 2025-12-08T00:00:00Z" Jan 28 09:49:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:49:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:49:24 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:49:24 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:49:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:49:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699526. Jan 28 09:49:25 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:49:25 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:49:25 volumio go-librespot[4652]: Librespot-go daemon starting... Jan 28 09:49:25 volumio go-librespot[4652]: time="2024-01-28T09:49:25Z" level=info msg="generated new device id: d51adf53106468188f24d1025cc47b06f4833d8f" Jan 28 09:49:25 volumio go-librespot[4652]: time="2024-01-28T09:49:25Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:49:25Z is before 2025-12-08T00:00:00Z" Jan 28 09:49:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:49:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:49:27 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:49:27 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:49:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:49:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699527. Jan 28 09:49:28 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:49:28 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:49:28 volumio go-librespot[4678]: Librespot-go daemon starting... Jan 28 09:49:28 volumio go-librespot[4678]: time="2024-01-28T09:49:28Z" level=info msg="generated new device id: ea23cda3eda9be0d06378059cc5152a09adb9b4b" Jan 28 09:49:28 volumio go-librespot[4678]: time="2024-01-28T09:49:28Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:49:28Z is before 2025-12-08T00:00:00Z" Jan 28 09:49:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:49:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:49:30 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:49:30 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:49:31 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:49:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699528. Jan 28 09:49:31 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:49:31 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:49:31 volumio go-librespot[4708]: Librespot-go daemon starting... Jan 28 09:49:31 volumio go-librespot[4708]: time="2024-01-28T09:49:31Z" level=info msg="generated new device id: 1aaf3c60ec3f539bb552844427fbf15398968871" Jan 28 09:49:32 volumio go-librespot[4708]: time="2024-01-28T09:49:32Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:49:31Z is before 2025-12-08T00:00:00Z" Jan 28 09:49:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:49:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:49:33 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:49:33 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:49:35 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:49:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699529. Jan 28 09:49:35 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:49:35 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:49:35 volumio go-librespot[4723]: Librespot-go daemon starting... Jan 28 09:49:35 volumio go-librespot[4723]: time="2024-01-28T09:49:35Z" level=info msg="generated new device id: b617c057ece75751c110b459a34ae1111111f116" Jan 28 09:49:35 volumio go-librespot[4723]: time="2024-01-28T09:49:35Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:49:35Z is before 2025-12-08T00:00:00Z" Jan 28 09:49:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:49:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:49:36 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:49:36 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:49:38 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:49:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699530. Jan 28 09:49:38 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:49:38 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:49:38 volumio go-librespot[4749]: Librespot-go daemon starting... Jan 28 09:49:38 volumio go-librespot[4749]: time="2024-01-28T09:49:38Z" level=info msg="generated new device id: 9022f6bf43758f63bb765b2e6f07bf4701eb8cd2" Jan 28 09:49:38 volumio go-librespot[4749]: time="2024-01-28T09:49:38Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:49:38Z is before 2025-12-08T00:00:00Z" Jan 28 09:49:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:49:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:49:39 volumio volumio[813]: info: Preload queue cleared Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::ClearQueue Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::stop Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::stPlaybackTimer Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::updateTrackBlock Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrackBlock Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 2 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::serviceStop Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 2 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::serviceStop Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::stop Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand stop Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::clearPlayQueue Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::saveQueue Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushQueue Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::addQueueItems Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::addQueueItems Jan 28 09:49:39 volumio volumio[813]: info: Preload queue cleared Jan 28 09:49:39 volumio volumio[813]: info: Adding Item to queue: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 01. Here With Me.flac Jan 28 09:49:39 volumio volumio[813]: info: Using cached record of: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 01. Here With Me.flac Jan 28 09:49:39 volumio volumio[813]: info: Adding Item to queue: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 02. Hunter.flac Jan 28 09:49:39 volumio volumio[813]: info: Using cached record of: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 02. Hunter.flac Jan 28 09:49:39 volumio volumio[813]: info: Adding Item to queue: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 03. Don't Think Of Me.flac Jan 28 09:49:39 volumio volumio[813]: info: Using cached record of: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 03. Don't Think Of Me.flac Jan 28 09:49:39 volumio volumio[813]: info: Adding Item to queue: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 04. My Lover's Gone.flac Jan 28 09:49:39 volumio volumio[813]: info: Using cached record of: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 04. My Lover's Gone.flac Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushQueue Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::saveQueue Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::updateTrackBlock Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrackBlock Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPlay Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::play index 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::addQueueItems Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::addQueueItems Jan 28 09:49:39 volumio volumio[813]: info: Preload queue cleared Jan 28 09:49:39 volumio volumio[813]: info: Adding Item to queue: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 05. All You Want.flac Jan 28 09:49:39 volumio volumio[813]: info: Using cached record of: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 05. All You Want.flac Jan 28 09:49:39 volumio volumio[813]: info: Adding Item to queue: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 06. Thank You.flac Jan 28 09:49:39 volumio volumio[813]: info: Using cached record of: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 06. Thank You.flac Jan 28 09:49:39 volumio volumio[813]: info: Adding Item to queue: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 07. Honestly OK.flac Jan 28 09:49:39 volumio volumio[813]: info: Using cached record of: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 07. Honestly OK.flac Jan 28 09:49:39 volumio volumio[813]: info: Adding Item to queue: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 08. Slide.flac Jan 28 09:49:39 volumio volumio[813]: info: Using cached record of: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 08. Slide.flac Jan 28 09:49:39 volumio volumio[813]: info: Adding Item to queue: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 09. Isobel.flac Jan 28 09:49:39 volumio volumio[813]: info: Using cached record of: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 09. Isobel.flac Jan 28 09:49:39 volumio volumio[813]: info: Adding Item to queue: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 10. I'm No Angel.flac Jan 28 09:49:39 volumio volumio[813]: info: Using cached record of: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 10. I'm No Angel.flac Jan 28 09:49:39 volumio volumio[813]: info: Adding Item to queue: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 11. My Life.flac Jan 28 09:49:39 volumio volumio[813]: info: Using cached record of: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 11. My Life.flac Jan 28 09:49:39 volumio volumio[813]: info: Adding Item to queue: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 12. Take My Hand (Bonus Track).flac Jan 28 09:49:39 volumio volumio[813]: info: Using cached record of: music-library/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 12. Take My Hand (Bonus Track).flac Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::stop Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushQueue Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::saveQueue Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::play index undefined Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::updateTrackBlock Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrackBlock Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::startPlaybackTimer Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::clearAddPlayTracks USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 04. My Lover's Gone.flac Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand stop Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand stop took 21 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand stop took 8 milliseconds Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand clear Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces system playlist update Jan 28 09:49:39 volumio volumio[813]: info: Ignoring MPD Status Update Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand status took 5 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand clear took 4 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand status took 4 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand status took 3 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand status took 2 milliseconds Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand add "USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 04. My Lover's Gone.flac" Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseState Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::pushState Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::servicePushState Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: 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} Jan 28 09:49:39 volumio volumio[813]: verbose: CURRENT POSITION 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState stateService stop Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState currentStatus stop Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: No code Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::pushState Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::servicePushState Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: 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} Jan 28 09:49:39 volumio volumio[813]: verbose: CURRENT POSITION 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState stateService stop Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState currentStatus stop Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: No code Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::pushState Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::servicePushState Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: 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} Jan 28 09:49:39 volumio volumio[813]: verbose: CURRENT POSITION 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState stateService stop Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState currentStatus stop Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: No code Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: ------------------------------ 23ms Jan 28 09:49:39 volumio volumio[813]: info: ------------------------------ 23ms Jan 28 09:49:39 volumio volumio[813]: info: ------------------------------ 23ms Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces system playlist update Jan 28 09:49:39 volumio volumio[813]: info: Ignoring MPD Status Update Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces system playlist update Jan 28 09:49:39 volumio volumio[813]: info: Ignoring MPD Status Update Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces system playlist update Jan 28 09:49:39 volumio volumio[813]: info: Ignoring MPD Status Update Jan 28 09:49:39 volumio volumio[813]: error: updateQueue error: null Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces system playlist update Jan 28 09:49:39 volumio volumio[813]: info: Ignoring MPD Status Update Jan 28 09:49:39 volumio volumio[813]: info: ------------------------------ 25ms Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand playlistinfo took 24 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand add "USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 04. My Lover's Gone.flac" took 24 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: ------------------------------ 4ms Jan 28 09:49:39 volumio volumio[813]: info: ------------------------------ 3ms Jan 28 09:49:39 volumio volumio[813]: info: ------------------------------ 2ms Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseTrackInfo Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand play Jan 28 09:49:39 volumio volumio[813]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jan 28 09:49:39 volumio volumio[813]: info: ------------------------------ 32ms Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces system playlist update Jan 28 09:49:39 volumio volumio[813]: info: Ignoring MPD Status Update Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces system playlist update Jan 28 09:49:39 volumio volumio[813]: info: Ignoring MPD Status Update Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces system playlist update Jan 28 09:49:39 volumio volumio[813]: info: Ignoring MPD Status Update Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: info: ------------------------------ 23ms Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand play took 21 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: ------------------------------ 20ms Jan 28 09:49:39 volumio volumio[813]: info: ------------------------------ 19ms Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:39 volumio volumio[813]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 28 09:49:39 volumio volumio[813]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 28 09:49:39 volumio volumio[813]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand status took 27 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand status took 29 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand status took 29 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand status took 28 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand status took 4 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand playlistinfo took 3 milliseconds Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseTrackInfo Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::pushState Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::servicePushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":268,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"380 Kbps","isStreaming":false,"title":"My Lover's Gone","artist":"Dido","album":"No Angel (Special Edition)","uri":"USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 04. My Lover's Gone.flac","trackType":"flac"} Jan 28 09:49:39 volumio volumio[813]: verbose: CURRENT POSITION 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState stateService play Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState currentStatus stop Jan 28 09:49:39 volumio volumio[813]: info: ------------------------------ 36ms Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:39 volumio volumio[813]: info: Jan 28 09:49:39 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand playlistinfo took 9 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand playlistinfo took 9 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand playlistinfo took 9 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand playlistinfo took 8 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand status took 5 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand status took 4 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand status took 3 milliseconds Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseTrackInfo Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseTrackInfo Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseTrackInfo Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseTrackInfo Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseState Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::pushState Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::servicePushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: verbose: STATE SERVICE {"status":"play","position":0,"seek":915,"duration":268,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"453 Kbps","isStreaming":false,"title":"My Lover's Gone","artist":"Dido","album":"No Angel (Special Edition)","uri":"USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 04. My Lover's Gone.flac","trackType":"flac"} Jan 28 09:49:39 volumio volumio[813]: verbose: CURRENT POSITION 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState stateService play Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState currentStatus play Jan 28 09:49:39 volumio volumio[813]: info: Received an update from plugin. extracting info from payload Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::pushState Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::servicePushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":268,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"453 Kbps","isStreaming":false,"title":"My Lover's Gone","artist":"Dido","album":"No Angel (Special Edition)","uri":"USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 04. My Lover's Gone.flac","trackType":"flac"} Jan 28 09:49:39 volumio volumio[813]: verbose: CURRENT POSITION 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState stateService play Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState currentStatus play Jan 28 09:49:39 volumio volumio[813]: info: Received an update from plugin. extracting info from payload Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::pushState Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::servicePushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":268,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"453 Kbps","isStreaming":false,"title":"My Lover's Gone","artist":"Dido","album":"No Angel (Special Edition)","uri":"USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 04. My Lover's Gone.flac","trackType":"flac"} Jan 28 09:49:39 volumio volumio[813]: verbose: CURRENT POSITION 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState stateService play Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState currentStatus play Jan 28 09:49:39 volumio volumio[813]: info: Received an update from plugin. extracting info from payload Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::pushState Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::servicePushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":268,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"453 Kbps","isStreaming":false,"title":"My Lover's Gone","artist":"Dido","album":"No Angel (Special Edition)","uri":"USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 04. My Lover's Gone.flac","trackType":"flac"} Jan 28 09:49:39 volumio volumio[813]: verbose: CURRENT POSITION 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState stateService play Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState currentStatus play Jan 28 09:49:39 volumio volumio[813]: info: Received an update from plugin. extracting info from payload Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: ------------------------------ 69ms Jan 28 09:49:39 volumio volumio[813]: info: ------------------------------ 68ms Jan 28 09:49:39 volumio volumio[813]: info: ------------------------------ 68ms Jan 28 09:49:39 volumio volumio[813]: info: ------------------------------ 45ms Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand playlistinfo took 29 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand playlistinfo took 29 milliseconds Jan 28 09:49:39 volumio volumio[813]: info: sendMpdCommand playlistinfo took 29 milliseconds Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseTrackInfo Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseTrackInfo Jan 28 09:49:39 volumio volumio[813]: verbose: ControllerMpd::parseTrackInfo Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::pushState Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::servicePushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":268,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"453 Kbps","isStreaming":false,"title":"My Lover's Gone","artist":"Dido","album":"No Angel (Special Edition)","uri":"USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 04. My Lover's Gone.flac","trackType":"flac"} Jan 28 09:49:39 volumio volumio[813]: verbose: CURRENT POSITION 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState stateService play Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState currentStatus play Jan 28 09:49:39 volumio volumio[813]: info: Received an update from plugin. extracting info from payload Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::pushState Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::servicePushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":268,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"453 Kbps","isStreaming":false,"title":"My Lover's Gone","artist":"Dido","album":"No Angel (Special Edition)","uri":"USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 04. My Lover's Gone.flac","trackType":"flac"} Jan 28 09:49:39 volumio volumio[813]: verbose: CURRENT POSITION 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState stateService play Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState currentStatus play Jan 28 09:49:39 volumio volumio[813]: info: Received an update from plugin. extracting info from payload Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: ControllerMpd::pushState Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::servicePushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":268,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"453 Kbps","isStreaming":false,"title":"My Lover's Gone","artist":"Dido","album":"No Angel (Special Edition)","uri":"USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 04. My Lover's Gone.flac","trackType":"flac"} Jan 28 09:49:39 volumio volumio[813]: verbose: CURRENT POSITION 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState stateService play Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::syncState currentStatus play Jan 28 09:49:39 volumio volumio[813]: info: Received an update from plugin. extracting info from payload Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:39 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:39 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:39 volumio volumio[813]: info: ------------------------------ 49ms Jan 28 09:49:39 volumio volumio[813]: info: ------------------------------ 49ms Jan 28 09:49:39 volumio volumio[813]: info: ------------------------------ 48ms Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: info: FusionDsp - eq1: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 25 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq2: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 40 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq3: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 63 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq4: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 100 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq5: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 160 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq6: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 250 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq7: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 400 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq8: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 630 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq9: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 1000 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq10: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 1600 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq11: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 2500 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq12: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 4000 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq13: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 6300 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq14: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 10000 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq15: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 16000 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq16: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 25 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq17: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 40 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq18: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 63 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq19: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 100 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq20: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 160 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq21: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 250 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq22: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 400 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq23: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 630 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq24: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 1000 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq25: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 1600 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq26: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 2500 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq27: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 4000 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq28: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 6300 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq29: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 10000 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: eq30: Jan 28 09:49:39 volumio volumio[813]: type: Biquad Jan 28 09:49:39 volumio volumio[813]: parameters: Jan 28 09:49:39 volumio volumio[813]: type: Peaking Jan 28 09:49:39 volumio volumio[813]: freq: 16000 Jan 28 09:49:39 volumio volumio[813]: q: 1.85 Jan 28 09:49:39 volumio volumio[813]: gain: 0 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:39 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:39 volumio volumio[813]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jan 28 09:49:39 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:49:39 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:49:42 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:49:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699531. Jan 28 09:49:42 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:49:42 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:49:42 volumio go-librespot[4788]: Librespot-go daemon starting... Jan 28 09:49:42 volumio go-librespot[4788]: time="2024-01-28T09:49:42Z" level=info msg="generated new device id: 3b35dfcbbfdfc43cadd57c15c155318774058772" Jan 28 09:49:42 volumio go-librespot[4788]: time="2024-01-28T09:49:42Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:49:42Z is before 2025-12-08T00:00:00Z" Jan 28 09:49:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:49:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:49:42 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:49:42 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:49:43 volumio volumio[813]: info: CoreCommandRouter::volumioSeek Jan 28 09:49:43 volumio volumio[813]: info: CoreStateMachine::seek Jan 28 09:49:43 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:43 volumio volumio[813]: info: TRACKBLOCK {"uri":"mnt/USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 04. My Lover's Gone.flac","service":"mpd","name":"My Lover's Gone","artist":"Dido","album":"No Angel (Special Edition)","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=600&web=Dido/No%20Angel%20(Special%20Edition)/extralarge&path=%2FUSB%2FBackup_Plus%2FStorage%2FMusic%2F_flac%2FDido%2FDido-No%20Angel&metadata=false","duration":268,"samplerate":"44.1 kHz","bitdepth":"16 bit","trackType":"flac","channels":2} Jan 28 09:49:43 volumio volumio[813]: info: CoreStateMachine::startPlaybackTimer Jan 28 09:49:43 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:43 volumio volumio[813]: info: ControllerMpd::seek Jan 28 09:49:43 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:43 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:43 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 09:49:43 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:43 volumio volumio[813]: error: null Jan 28 09:49:43 volumio volumio[813]: info: Jan 28 09:49:43 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:43 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:43 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:43 volumio volumio[813]: info: Jan 28 09:49:43 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:43 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:43 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:43 volumio volumio[813]: info: Jan 28 09:49:43 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:43 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:43 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:43 volumio volumio[813]: info: Jan 28 09:49:43 volumio volumio[813]: ---------------------------- MPD announces state update: player Jan 28 09:49:43 volumio volumio[813]: info: ControllerMpd::getState Jan 28 09:49:43 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand status Jan 28 09:49:43 volumio volumio[813]: info: sendMpdCommand status took 8 milliseconds Jan 28 09:49:43 volumio volumio[813]: info: sendMpdCommand status took 6 milliseconds Jan 28 09:49:43 volumio volumio[813]: info: sendMpdCommand status took 5 milliseconds Jan 28 09:49:43 volumio volumio[813]: info: sendMpdCommand status took 4 milliseconds Jan 28 09:49:43 volumio volumio[813]: verbose: ControllerMpd::parseState Jan 28 09:49:43 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 09:49:43 volumio volumio[813]: verbose: ControllerMpd::parseState Jan 28 09:49:43 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 09:49:43 volumio volumio[813]: verbose: ControllerMpd::parseState Jan 28 09:49:43 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 09:49:43 volumio volumio[813]: verbose: ControllerMpd::parseState Jan 28 09:49:43 volumio volumio[813]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 09:49:43 volumio volumio[813]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 28 09:49:43 volumio volumio[813]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 28 09:49:43 volumio volumio[813]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 28 09:49:43 volumio volumio[813]: info: sendMpdCommand playlistinfo took 4 milliseconds Jan 28 09:49:43 volumio volumio[813]: verbose: ControllerMpd::parseTrackInfo Jan 28 09:49:43 volumio volumio[813]: verbose: ControllerMpd::parseTrackInfo Jan 28 09:49:43 volumio volumio[813]: verbose: ControllerMpd::parseTrackInfo Jan 28 09:49:43 volumio volumio[813]: verbose: ControllerMpd::parseTrackInfo Jan 28 09:49:43 volumio volumio[813]: info: ControllerMpd::pushState Jan 28 09:49:43 volumio volumio[813]: info: CoreCommandRouter::servicePushState Jan 28 09:49:43 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:43 volumio volumio[813]: verbose: STATE SERVICE {"status":"play","position":0,"seek":45000,"duration":268,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"795 Kbps","isStreaming":false,"title":"My Lover's Gone","artist":"Dido","album":"No Angel (Special Edition)","uri":"USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 04. My Lover's Gone.flac","trackType":"flac"} Jan 28 09:49:43 volumio volumio[813]: verbose: CURRENT POSITION 3 Jan 28 09:49:43 volumio volumio[813]: info: CoreStateMachine::syncState stateService play Jan 28 09:49:43 volumio volumio[813]: info: CoreStateMachine::syncState currentStatus play Jan 28 09:49:43 volumio volumio[813]: info: Received an update from plugin. extracting info from payload Jan 28 09:49:43 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:43 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:43 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:43 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:43 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:43 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:43 volumio volumio[813]: info: ControllerMpd::pushState Jan 28 09:49:43 volumio volumio[813]: info: CoreCommandRouter::servicePushState Jan 28 09:49:43 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:43 volumio volumio[813]: verbose: STATE SERVICE {"status":"play","position":0,"seek":45960,"duration":268,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"767 Kbps","isStreaming":false,"title":"My Lover's Gone","artist":"Dido","album":"No Angel (Special Edition)","uri":"USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 04. My Lover's Gone.flac","trackType":"flac"} Jan 28 09:49:43 volumio volumio[813]: verbose: CURRENT POSITION 3 Jan 28 09:49:43 volumio volumio[813]: info: CoreStateMachine::syncState stateService play Jan 28 09:49:43 volumio volumio[813]: info: CoreStateMachine::syncState currentStatus play Jan 28 09:49:43 volumio volumio[813]: info: Received an update from plugin. extracting info from payload Jan 28 09:49:43 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:43 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:43 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 09:49:43 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:43 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:43 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:43 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:43 volumio volumio[813]: info: ControllerMpd::pushState Jan 28 09:49:43 volumio volumio[813]: info: CoreCommandRouter::servicePushState Jan 28 09:49:43 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:43 volumio volumio[813]: verbose: STATE SERVICE {"status":"play","position":0,"seek":45960,"duration":268,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"749 Kbps","isStreaming":false,"title":"My Lover's Gone","artist":"Dido","album":"No Angel (Special Edition)","uri":"USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 04. My Lover's Gone.flac","trackType":"flac"} Jan 28 09:49:43 volumio volumio[813]: verbose: CURRENT POSITION 3 Jan 28 09:49:43 volumio volumio[813]: info: CoreStateMachine::syncState stateService play Jan 28 09:49:43 volumio volumio[813]: info: CoreStateMachine::syncState currentStatus play Jan 28 09:49:43 volumio volumio[813]: info: Received an update from plugin. extracting info from payload Jan 28 09:49:43 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:43 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:43 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:43 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:43 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:43 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:43 volumio volumio[813]: info: ControllerMpd::pushState Jan 28 09:49:43 volumio volumio[813]: info: CoreCommandRouter::servicePushState Jan 28 09:49:43 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:43 volumio volumio[813]: verbose: STATE SERVICE {"status":"play","position":0,"seek":45960,"duration":268,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"698 Kbps","isStreaming":false,"title":"My Lover's Gone","artist":"Dido","album":"No Angel (Special Edition)","uri":"USB/Backup_Plus/Storage/Music/_flac/Dido/Dido-No Angel/Dido 04. My Lover's Gone.flac","trackType":"flac"} Jan 28 09:49:43 volumio volumio[813]: verbose: CURRENT POSITION 3 Jan 28 09:49:43 volumio volumio[813]: info: CoreStateMachine::syncState stateService play Jan 28 09:49:43 volumio volumio[813]: info: CoreStateMachine::syncState currentStatus play Jan 28 09:49:43 volumio volumio[813]: info: Received an update from plugin. extracting info from payload Jan 28 09:49:43 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:43 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:43 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:43 volumio volumio[813]: info: CoreStateMachine::pushState Jan 28 09:49:43 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:43 volumio volumio[813]: info: CoreCommandRouter::volumioPushState Jan 28 09:49:43 volumio volumio[813]: info: ------------------------------ 51ms Jan 28 09:49:43 volumio volumio[813]: info: ------------------------------ 49ms Jan 28 09:49:43 volumio volumio[813]: info: ------------------------------ 47ms Jan 28 09:49:43 volumio volumio[813]: info: ------------------------------ 46ms Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:43 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:45 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:49:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699532. Jan 28 09:49:45 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:49:45 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:49:45 volumio go-librespot[4804]: Librespot-go daemon starting... Jan 28 09:49:45 volumio go-librespot[4804]: time="2024-01-28T09:49:45Z" level=info msg="generated new device id: 3229d0651ce4a1597ebb7791bf4ae7e52ed1e7e7" Jan 28 09:49:45 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:49:45 volumio go-librespot[4804]: time="2024-01-28T09:49:45Z" level=debug msg="new websocket client" Jan 28 09:49:45 volumio volumio[813]: info: Connection to go-librespot Websocket established Jan 28 09:49:45 volumio go-librespot[4804]: time="2024-01-28T09:49:45Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:49:45Z is before 2025-12-08T00:00:00Z" Jan 28 09:49:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:49:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:49:45 volumio volumio[813]: info: Connection to go-librespot Websocket closed Jan 28 09:49:48 volumio volumio[813]: info: Getting Spotify volume Jan 28 09:49:48 volumio volumio[813]: (node:813) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:49:48 volumio volumio[813]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jan 28 09:49:48 volumio volumio[813]: (node:813) 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: 32407) Jan 28 09:49:48 volumio volumio[813]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jan 28 09:49:48 volumio volumio[813]: info: CoreCommandRouter::volumioGetState Jan 28 09:49:48 volumio volumio[813]: info: CorePlayQueue::getTrack 3 Jan 28 09:49:48 volumio volumio[813]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Jan 28 09:49:48 volumio volumio[813]: SPOTIFY: SPOTIFY VOLUME 15 Jan 28 09:49:48 volumio volumio[813]: SPOTIFY: VOLUMIO VOLUME 16 Jan 28 09:49:48 volumio volumio[813]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 28 09:49:48 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:49:48 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:49:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:49:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699533. Jan 28 09:49:48 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:49:48 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:49:48 volumio go-librespot[4829]: Librespot-go daemon starting... Jan 28 09:49:48 volumio go-librespot[4829]: time="2024-01-28T09:49:48Z" level=info msg="generated new device id: 0b2276b519d25ddc2ccde22ebf4c63ea46172c5c" Jan 28 09:49:49 volumio go-librespot[4829]: time="2024-01-28T09:49:49Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:49:48Z is before 2025-12-08T00:00:00Z" Jan 28 09:49:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:49:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:49:51 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:49:51 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:49:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:49:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699534. Jan 28 09:49:52 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:49:52 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:49:52 volumio go-librespot[4859]: Librespot-go daemon starting... Jan 28 09:49:52 volumio go-librespot[4859]: time="2024-01-28T09:49:52Z" level=info msg="generated new device id: 21c1b437f5089e9d5b288f09e87ae6f6dc397964" Jan 28 09:49:52 volumio go-librespot[4859]: time="2024-01-28T09:49:52Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:49:52Z is before 2025-12-08T00:00:00Z" Jan 28 09:49:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:49:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:49:53 volumio volumio[813]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Caravan/Where%20But%20For%20Caravan%20Would%20I%20(Disc%202)/9df2dc52-aa73-4624-a101-0a45677b6c7d.jpg' Jan 28 09:49:54 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jan 28 09:49:54 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 09:49:55 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 28 09:49:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699535. Jan 28 09:49:55 volumio systemd[1]: Stopped go-librespot Daemon. Jan 28 09:49:55 volumio systemd[1]: Started go-librespot Daemon. Jan 28 09:49:55 volumio go-librespot[4873]: Librespot-go daemon starting... Jan 28 09:49:55 volumio go-librespot[4873]: time="2024-01-28T09:49:55Z" level=info msg="generated new device id: b6af8aa8264d1fca5f7a6ee699a1e53c84d71b49" Jan 28 09:49:55 volumio go-librespot[4873]: time="2024-01-28T09:49:55Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2024-01-28T09:49:55Z is before 2025-12-08T00:00:00Z" Jan 28 09:49:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 09:49:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 09:49:55 volumio volumio[813]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 09:49:55 volumio volumio[813]: Error: certificate is not yet valid Jan 28 09:49:55 volumio volumio[813]: at TLSSocket.onConnectSecure (_tls_wrap.js:1497:34) Jan 28 09:49:55 volumio volumio[813]: at TLSSocket.emit (events.js:315:20) Jan 28 09:49:55 volumio volumio[813]: at TLSSocket._finishInit (_tls_wrap.js:932:8) Jan 28 09:49:55 volumio volumio[813]: at TLSWrap.ssl.onhandshakedone (_tls_wrap.js:706:12) { Jan 28 09:49:55 volumio volumio[813]: code: 'CERT_NOT_YET_VALID' Jan 28 09:49:55 volumio volumio[813]: } Jan 28 09:49:55 volumio volumio[813]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 09:49:56 volumio sudo[4890]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-01-28 09:48 Jan 28 09:49:56 volumio sudo[4890]: 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="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"