-- Logs begin at Sun 2025-05-25 16:13:16 CEST, end at Sun 2025-05-25 16:26:35 CEST. -- May 25 16:25:06 volumio go-librespot[3149]: time="2025-05-25T16:25:06+02:00" level=debug msg="fetched chunk 11/18, size: 524288" uri="spotify:track:1ZlG9VQSUfSw0gJBzy7eEV" May 25 16:25:10 volumio go-librespot[3149]: time="2025-05-25T16:25:10+02:00" level=trace msg="sent dealer ping" May 25 16:25:10 volumio go-librespot[3149]: time="2025-05-25T16:25:10+02:00" level=trace msg="received dealer pong" May 25 16:25:15 volumio volumio[874]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] May 25 16:25:15 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings May 25 16:25:15 volumio volumio[874]: info: Creating Spotify config file May 25 16:25:15 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 25 16:25:15 volumio volumio[874]: info: Spotify config file written May 25 16:25:15 volumio sudo[3638]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 25 16:25:15 volumio sudo[3638]: pam_unix(sudo:session): session opened for user root by (uid=0) May 25 16:25:15 volumio systemd[1]: Stopping go-librespot Daemon... May 25 16:25:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM May 25 16:25:15 volumio systemd[1]: go-librespot-daemon.service: Succeeded. May 25 16:25:15 volumio systemd[1]: Stopped go-librespot Daemon. May 25 16:25:15 volumio volumio[874]: info: Connection to go-librespot Websocket closed May 25 16:25:15 volumio volumio[874]: info: Connection to go-librespot Websocket closed May 25 16:25:15 volumio volumio[874]: info: Connection to go-librespot Websocket closed May 25 16:25:15 volumio volumio[874]: info: Connection to go-librespot Websocket closed May 25 16:25:15 volumio systemd[1]: Started go-librespot Daemon. May 25 16:25:15 volumio go-librespot[3640]: go-librespot daemon starting... May 25 16:25:15 volumio sudo[3638]: pam_unix(sudo:session): session closed for user root May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=info msg="running go-librespot 0.2.0" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=debug msg="app state loaded" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=info msg="zeroconf server listening on port 36361" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=debug msg="obtained new client token: AABDyyNoGNjiwsJS74eHtebrNoCzimHd10Mt+s31099RZdzT4rVXQjNWMhGm/I1aOz0J1g0EOBR1DvBAUUR2JZZ/NhZ2cBaxIpXHUZjKQ4mqGkniQ6nohfY2gsfQvUhT/Q7wKzXt510oy9YOsgYRGq6rnAwCs1vS4tfZ8o72mnUrNAUpY+U/H8Ik4jxlIPmIoYNuiQESsyGnF9beyhxJ92Ev+EsmM6Qovlahqdqp1hNJPnoNj+MiEsBl4g==" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=debug msg="completed keyexchange" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=debug msg="completed challenge" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=info msg="authenticated AP as 31f7jkt63ujnwtfboix74we7wsni" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=info msg="authenticated Login5 as 31f7jkt63ujnwtfboix74we7wsni" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=debug msg="initializing zeroconf session, username: 31f7jkt63ujnwtfboix74we7wsni" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=debug msg="dealer connection opened" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=trace msg="starting accesspoint recv loop" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=trace msg="starting dealer recv loop" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=trace msg="received accesspoint ping" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 25 16:25:15 volumio go-librespot[3640]: time="2025-05-25T16:25:15+02:00" level=debug msg="received connection id: ODAxZGU0NDktODk0My00NzZlLTgzNjQtMTY1YzNkODVlYjU3K2RlYWxlcit0Y3A6Ly8wYWNhNDAzYy5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArQjc5OTI4MTJBODNERjg4QzIyNDc5QjlCRUYwQjU1RTJFMDE1QjAxNjAxREZBNTc1M0FEQkIwM0U0RDQzOTBDNg==" May 25 16:25:16 volumio go-librespot[3640]: time="2025-05-25T16:25:16+02:00" level=trace msg="received accesspoint pong ack" May 25 16:25:16 volumio go-librespot[3640]: time="2025-05-25T16:25:16+02:00" level=debug msg="put connect state because NEW_DEVICE" May 25 16:25:17 volumio volumio[874]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] May 25 16:25:17 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings May 25 16:25:17 volumio volumio[874]: info: Creating Spotify config file May 25 16:25:17 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 25 16:25:17 volumio volumio[874]: info: Spotify config file written May 25 16:25:17 volumio sudo[3664]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 25 16:25:17 volumio sudo[3664]: pam_unix(sudo:session): session opened for user root by (uid=0) May 25 16:25:17 volumio systemd[1]: Stopping go-librespot Daemon... May 25 16:25:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM May 25 16:25:17 volumio systemd[1]: go-librespot-daemon.service: Succeeded. May 25 16:25:17 volumio systemd[1]: Stopped go-librespot Daemon. May 25 16:25:17 volumio systemd[1]: Started go-librespot Daemon. May 25 16:25:17 volumio sudo[3664]: pam_unix(sudo:session): session closed for user root May 25 16:25:17 volumio go-librespot[3666]: go-librespot daemon starting... May 25 16:25:17 volumio go-librespot[3666]: time="2025-05-25T16:25:17+02:00" level=info msg="running go-librespot 0.2.0" May 25 16:25:17 volumio go-librespot[3666]: time="2025-05-25T16:25:17+02:00" level=debug msg="app state loaded" May 25 16:25:17 volumio go-librespot[3666]: time="2025-05-25T16:25:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 25 16:25:17 volumio go-librespot[3666]: time="2025-05-25T16:25:17+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 25 16:25:17 volumio go-librespot[3666]: time="2025-05-25T16:25:17+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 25 16:25:17 volumio go-librespot[3666]: time="2025-05-25T16:25:17+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 25 16:25:17 volumio go-librespot[3666]: time="2025-05-25T16:25:17+02:00" level=info msg="zeroconf server listening on port 45265" May 25 16:25:17 volumio go-librespot[3666]: time="2025-05-25T16:25:17+02:00" level=debug msg="obtained new client token: AAAKPyOc8Zz2E0T6sx85zhlwTZPrtwzflefis2Q4SwxQaP53+hRAt/cdRLJ2uKpd06TUcPX/SLPJ9K3hFWfH4omv7MiaA25Q3Pba5vLUcuDKkTGeoFC+tkly/ssdjaTMpoN2OvEuIBZV5Td8/GczUP/ouvdFgsw05sco9YKOrb7ewTVAodp1w/Oz7TbcQqXPP6juEOFsHfmHBU9e5hJpYSkFh2QZ0GDKYZ146yUjGbY1+C6IXKTrPfqFNw==" May 25 16:25:17 volumio go-librespot[3666]: time="2025-05-25T16:25:17+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" May 25 16:25:17 volumio go-librespot[3666]: time="2025-05-25T16:25:17+02:00" level=debug msg="completed keyexchange" May 25 16:25:17 volumio go-librespot[3666]: time="2025-05-25T16:25:17+02:00" level=debug msg="completed challenge" May 25 16:25:17 volumio go-librespot[3666]: time="2025-05-25T16:25:17+02:00" level=info msg="authenticated AP as 31f7jkt63ujnwtfboix74we7wsni" May 25 16:25:17 volumio go-librespot[3666]: time="2025-05-25T16:25:17+02:00" level=info msg="authenticated Login5 as 31f7jkt63ujnwtfboix74we7wsni" May 25 16:25:17 volumio go-librespot[3666]: time="2025-05-25T16:25:17+02:00" level=debug msg="initializing zeroconf session, username: 31f7jkt63ujnwtfboix74we7wsni" May 25 16:25:18 volumio go-librespot[3666]: time="2025-05-25T16:25:18+02:00" level=debug msg="dealer connection opened" May 25 16:25:18 volumio go-librespot[3666]: time="2025-05-25T16:25:18+02:00" level=trace msg="starting accesspoint recv loop" May 25 16:25:18 volumio go-librespot[3666]: time="2025-05-25T16:25:18+02:00" level=trace msg="starting dealer recv loop" May 25 16:25:18 volumio go-librespot[3666]: time="2025-05-25T16:25:18+02:00" level=trace msg="received accesspoint ping" May 25 16:25:18 volumio go-librespot[3666]: time="2025-05-25T16:25:18+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 25 16:25:18 volumio go-librespot[3666]: time="2025-05-25T16:25:18+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 25 16:25:18 volumio go-librespot[3666]: time="2025-05-25T16:25:18+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 25 16:25:18 volumio go-librespot[3666]: time="2025-05-25T16:25:18+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 25 16:25:18 volumio go-librespot[3666]: time="2025-05-25T16:25:18+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 25 16:25:18 volumio go-librespot[3666]: time="2025-05-25T16:25:18+02:00" level=debug msg="received connection id: Mzg1MmVjOTEtOWJjNC00NGE5LTliZGItNzE1NTljYTE1ZmEyK2RlYWxlcit0Y3A6Ly8wYWNhNDE1MS5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArNTNENEZBRTdGREE2QUVFQzY3ODlFQThFMjVFMTdFMDFBMDQ5NjU0NEQxNjUwOTYyNzZEQzZBNzNEMjNENTMxQg==" May 25 16:25:18 volumio go-librespot[3666]: time="2025-05-25T16:25:18+02:00" level=trace msg="received accesspoint pong ack" May 25 16:25:18 volumio go-librespot[3666]: time="2025-05-25T16:25:18+02:00" level=debug msg="put connect state because NEW_DEVICE" May 25 16:25:18 volumio volumio[874]: info: Initializing connection to go-librespot Websocket May 25 16:25:18 volumio go-librespot[3666]: time="2025-05-25T16:25:18+02:00" level=debug msg="new websocket client" May 25 16:25:18 volumio volumio[874]: info: Connection to go-librespot Websocket established May 25 16:25:18 volumio volumio[874]: info: go-librespot daemon successfully initialized May 25 16:25:20 volumio go-librespot[3666]: time="2025-05-25T16:25:20+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 340" May 25 16:25:20 volumio go-librespot[3666]: time="2025-05-25T16:25:20+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1439" May 25 16:25:20 volumio go-librespot[3666]: time="2025-05-25T16:25:20+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 25 16:25:20 volumio go-librespot[3666]: time="2025-05-25T16:25:20+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 25 16:25:20 volumio volumio[874]: info: go-librespot daemon successfully initialized May 25 16:25:21 volumio volumio[874]: info: Getting Spotify volume May 25 16:25:21 volumio volumio[874]: info: Spotify volume: 100 May 25 16:25:21 volumio volumio[874]: info: Initializing connection to go-librespot Websocket May 25 16:25:21 volumio volumio[874]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 May 25 16:25:21 volumio go-librespot[3666]: time="2025-05-25T16:25:21+02:00" level=debug msg="new websocket client" May 25 16:25:21 volumio volumio[874]: info: Connection to go-librespot Websocket established May 25 16:25:21 volumio volumio[874]: info: CoreCommandRouter::volumioGetState May 25 16:25:21 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:21 volumio volumio[874]: SPOTIFY: SPOTIFY VOLUME 100 May 25 16:25:21 volumio volumio[874]: SPOTIFY: VOLUMIO VOLUME 27 May 25 16:25:21 volumio volumio[874]: SPOTIFY: DELTA VOLUME ENOUGH: true May 25 16:25:21 volumio volumio[874]: info: Setting Spotify Volume from Volumio: 27 May 25 16:25:21 volumio go-librespot[3666]: time="2025-05-25T16:25:21+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 25 16:25:21 volumio go-librespot[3666]: time="2025-05-25T16:25:21+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 340" May 25 16:25:23 volumio volumio[874]: SPOTIFY: SETTING SPOTIFY VOLUME 27 May 25 16:25:23 volumio volumio[874]: info: Sending Spotify command with payload to local API: /player/volume May 25 16:25:23 volumio go-librespot[3666]: time="2025-05-25T16:25:23+02:00" level=debug msg="update volume to 17694/65535" May 25 16:25:23 volumio volumio[874]: info: Initializing connection to go-librespot Websocket May 25 16:25:23 volumio go-librespot[3666]: time="2025-05-25T16:25:23+02:00" level=debug msg="new websocket client" May 25 16:25:23 volumio volumio[874]: info: Connection to go-librespot Websocket established May 25 16:25:24 volumio go-librespot[3666]: time="2025-05-25T16:25:24+02:00" level=debug msg="put connect state because VOLUME_CHANGED" May 25 16:25:24 volumio go-librespot[3666]: time="2025-05-25T16:25:24+02:00" level=trace msg="emitting websocket event: volume" May 25 16:25:24 volumio volumio[874]: SPOTIFY: received: {"type":"volume","data":{"value":27,"max":100}} May 25 16:25:24 volumio volumio[874]: SPOTIFY: RECEIVED SPOTIFY VOLUME 27 May 25 16:25:24 volumio volumio[874]: SPOTIFY: received: {"type":"volume","data":{"value":27,"max":100}} May 25 16:25:24 volumio volumio[874]: SPOTIFY: RECEIVED SPOTIFY VOLUME 27 May 25 16:25:24 volumio volumio[874]: SPOTIFY: received: {"type":"volume","data":{"value":27,"max":100}} May 25 16:25:24 volumio volumio[874]: SPOTIFY: RECEIVED SPOTIFY VOLUME 27 May 25 16:25:24 volumio volumio[874]: info: Getting Spotify volume May 25 16:25:24 volumio volumio[874]: info: Spotify volume: 27 May 25 16:25:24 volumio volumio[874]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 May 25 16:25:24 volumio volumio[874]: info: CoreCommandRouter::volumioGetState May 25 16:25:24 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:26 volumio volumio[874]: info: Getting Spotify volume May 25 16:25:26 volumio volumio[874]: info: Spotify volume: 27 May 25 16:25:26 volumio volumio[874]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 May 25 16:25:26 volumio volumio[874]: info: CoreCommandRouter::volumioGetState May 25 16:25:26 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="handling transfer player command from ba0e0c11dd7aabfc29bf13ebc065286eb20a6c00" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="resolved context of track" uri="spotify:playlist:61FqDPmb86D3Cjc0i5Gs1y" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=trace msg="fetched new page 0 with 67 items (list: 67)" uri="spotify:playlist:61FqDPmb86D3Cjc0i5Gs1y" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="shuffled context with seed 5146869739354633888 (len: 67, keep: 63)" uri="spotify:playlist:61FqDPmb86D3Cjc0i5Gs1y" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="loading track (paused: false, position: 109031ms)" uri="spotify:track:1ZlG9VQSUfSw0gJBzy7eEV" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=trace msg="emitting websocket event: will_play" May 25 16:25:27 volumio volumio[874]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","play_origin":"playlist"}} May 25 16:25:27 volumio volumio[874]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","play_origin":"playlist"}} May 25 16:25:27 volumio volumio[874]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","play_origin":"playlist"}} May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="selected format OGG_VORBIS_320 (fc8eef7c33c241f559ed5ccae5356fddd69053b8)" uri="spotify:track:1ZlG9VQSUfSw0gJBzy7eEV" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="requested aes key for file fc8eef7c33c241f559ed5ccae5356fddd69053b8, gid: 1ZlG9VQSUfSw0gJBzy7eEV" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1372" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="fetched first chunk of 19, total size is 9747358 bytes" uri="spotify:track:1ZlG9VQSUfSw0gJBzy7eEV" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1130" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:1ZlG9VQSUfSw0gJBzy7eEV" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:1ZlG9VQSUfSw0gJBzy7eEV" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:1ZlG9VQSUfSw0gJBzy7eEV" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="fetched chunk 9/18, size: 524288" uri="spotify:track:1ZlG9VQSUfSw0gJBzy7eEV" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=trace msg="seek to 109031ms (diff: 195ms, samples: 4808267, bytes: 4929612)" uri="spotify:track:1ZlG9VQSUfSw0gJBzy7eEV" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="created new output device" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="fetched chunk 11/18, size: 524288" uri="spotify:track:1ZlG9VQSUfSw0gJBzy7eEV" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=info msg="loaded track \"La pêche à la ligne\" (paused: false, position: 109031ms, duration: 214466ms, prefetched: false)" uri="spotify:track:1ZlG9VQSUfSw0gJBzy7eEV" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=trace msg="scheduling prefetch in 76s" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=trace msg="emitting websocket event: metadata" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=trace msg="emitting websocket event: active" May 25 16:25:27 volumio volumio[874]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","name":"La pêche à la ligne","artist_names":["Renaud"],"album_name":"Mistral gagnant","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02dd3a17393ca3f47e4c523c26","position":109031,"duration":214466,"release_date":"year:1985","track_number":2,"disc_number":1}} May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="sending successful reply for dealer request" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 25 16:25:27 volumio volumio[874]: SPOTIFY: received: {"type":"active","data":null} May 25 16:25:27 volumio volumio[874]: info: Aligning Spotify Volume to Volumio Volume May 25 16:25:27 volumio volumio[874]: info: CoreCommandRouter::volumioGetState May 25 16:25:27 volumio volumio[874]: info: Setting Spotify Volume from Volumio: 27 May 25 16:25:27 volumio volumio[874]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","name":"La pêche à la ligne","artist_names":["Renaud"],"album_name":"Mistral gagnant","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02dd3a17393ca3f47e4c523c26","position":109031,"duration":214466,"release_date":"year:1985","track_number":2,"disc_number":1}} May 25 16:25:27 volumio volumio[874]: SPOTIFY: received: {"type":"active","data":null} May 25 16:25:27 volumio volumio[874]: info: Aligning Spotify Volume to Volumio Volume May 25 16:25:27 volumio volumio[874]: info: CoreCommandRouter::volumioGetState May 25 16:25:27 volumio volumio[874]: info: Setting Spotify Volume from Volumio: 27 May 25 16:25:27 volumio volumio[874]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","name":"La pêche à la ligne","artist_names":["Renaud"],"album_name":"Mistral gagnant","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02dd3a17393ca3f47e4c523c26","position":109031,"duration":214466,"release_date":"year:1985","track_number":2,"disc_number":1}} May 25 16:25:27 volumio volumio[874]: SPOTIFY: received: {"type":"active","data":null} May 25 16:25:27 volumio volumio[874]: info: Aligning Spotify Volume to Volumio Volume May 25 16:25:27 volumio volumio[874]: info: CoreCommandRouter::volumioGetState May 25 16:25:27 volumio volumio[874]: info: Setting Spotify Volume from Volumio: 27 May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="fetched chunk 12/18, size: 524288" uri="spotify:track:1ZlG9VQSUfSw0gJBzy7eEV" May 25 16:25:27 volumio go-librespot[3666]: time="2025-05-25T16:25:27+02:00" level=debug msg="fetched chunk 10/18, size: 524288" uri="spotify:track:1ZlG9VQSUfSw0gJBzy7eEV" May 25 16:25:28 volumio go-librespot[3666]: time="2025-05-25T16:25:28+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 25 16:25:28 volumio go-librespot[3666]: time="2025-05-25T16:25:28+02:00" level=trace msg="emitting websocket event: playing" May 25 16:25:28 volumio volumio[874]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","play_origin":"playlist"}} May 25 16:25:28 volumio volumio[874]: SPOTIFY: PUSH STATE SPOTIFY May 25 16:25:28 volumio volumio[874]: SPOTIFY: {"status":"play","service":"spop","title":"La pêche à la ligne","artist":"Renaud","album":"Mistral gagnant","albumart":"https://i.scdn.co/image/ab67616d00001e02dd3a17393ca3f47e4c523c26","uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","trackType":"spotify","seek":109031,"duration":214,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 25 16:25:28 volumio volumio[874]: info: CoreCommandRouter::servicePushState May 25 16:25:28 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:28 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 25 16:25:28 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:28 volumio volumio[874]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","play_origin":"playlist"}} May 25 16:25:28 volumio volumio[874]: SPOTIFY: PUSH STATE SPOTIFY May 25 16:25:28 volumio volumio[874]: SPOTIFY: {"status":"play","service":"spop","title":"La pêche à la ligne","artist":"Renaud","album":"Mistral gagnant","albumart":"https://i.scdn.co/image/ab67616d00001e02dd3a17393ca3f47e4c523c26","uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","trackType":"spotify","seek":109031,"duration":214,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 25 16:25:28 volumio volumio[874]: info: CoreCommandRouter::servicePushState May 25 16:25:28 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:28 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:28 volumio volumio[874]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","play_origin":"playlist"}} May 25 16:25:28 volumio volumio[874]: SPOTIFY: PUSH STATE SPOTIFY May 25 16:25:28 volumio volumio[874]: SPOTIFY: {"status":"play","service":"spop","title":"La pêche à la ligne","artist":"Renaud","album":"Mistral gagnant","albumart":"https://i.scdn.co/image/ab67616d00001e02dd3a17393ca3f47e4c523c26","uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","trackType":"spotify","seek":109031,"duration":214,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 25 16:25:28 volumio volumio[874]: info: CoreCommandRouter::servicePushState May 25 16:25:28 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:28 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:28 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:28 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:28 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:28 volumio volumio[874]: SPOTIFY: PUSH STATE SPOTIFY May 25 16:25:28 volumio volumio[874]: SPOTIFY: {"status":"play","service":"spop","title":"La pêche à la ligne","artist":"Renaud","album":"Mistral gagnant","albumart":"https://i.scdn.co/image/ab67616d00001e02dd3a17393ca3f47e4c523c26","uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","trackType":"spotify","seek":109031,"duration":214,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 25 16:25:28 volumio volumio[874]: info: CoreCommandRouter::servicePushState May 25 16:25:28 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:28 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:28 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:28 volumio volumio[874]: SPOTIFY: PUSH STATE SPOTIFY May 25 16:25:28 volumio volumio[874]: SPOTIFY: {"status":"play","service":"spop","title":"La pêche à la ligne","artist":"Renaud","album":"Mistral gagnant","albumart":"https://i.scdn.co/image/ab67616d00001e02dd3a17393ca3f47e4c523c26","uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","trackType":"spotify","seek":109031,"duration":214,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 25 16:25:28 volumio volumio[874]: info: CoreCommandRouter::servicePushState May 25 16:25:28 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:28 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:28 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:28 volumio volumio[874]: SPOTIFY: PUSH STATE SPOTIFY May 25 16:25:28 volumio volumio[874]: SPOTIFY: {"status":"play","service":"spop","title":"La pêche à la ligne","artist":"Renaud","album":"Mistral gagnant","albumart":"https://i.scdn.co/image/ab67616d00001e02dd3a17393ca3f47e4c523c26","uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","trackType":"spotify","seek":109031,"duration":214,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 25 16:25:28 volumio volumio[874]: info: CoreCommandRouter::servicePushState May 25 16:25:28 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:28 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:28 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:29 volumio volumio[874]: SPOTIFY: SETTING SPOTIFY VOLUME 27 May 25 16:25:29 volumio volumio[874]: info: Sending Spotify command with payload to local API: /player/volume May 25 16:25:29 volumio go-librespot[3666]: time="2025-05-25T16:25:29+02:00" level=debug msg="update volume to 17694/65535" May 25 16:25:30 volumio go-librespot[3666]: time="2025-05-25T16:25:30+02:00" level=debug msg="put connect state because VOLUME_CHANGED" May 25 16:25:30 volumio go-librespot[3666]: time="2025-05-25T16:25:30+02:00" level=trace msg="emitting websocket event: volume" May 25 16:25:30 volumio volumio[874]: SPOTIFY: received: {"type":"volume","data":{"value":27,"max":100}} May 25 16:25:30 volumio volumio[874]: SPOTIFY: RECEIVED SPOTIFY VOLUME 27 May 25 16:25:30 volumio volumio[874]: SPOTIFY: received: {"type":"volume","data":{"value":27,"max":100}} May 25 16:25:30 volumio volumio[874]: SPOTIFY: RECEIVED SPOTIFY VOLUME 27 May 25 16:25:30 volumio volumio[874]: SPOTIFY: received: {"type":"volume","data":{"value":27,"max":100}} May 25 16:25:30 volumio volumio[874]: SPOTIFY: RECEIVED SPOTIFY VOLUME 27 May 25 16:25:33 volumio go-librespot[3666]: time="2025-05-25T16:25:33+02:00" level=debug msg="fetched chunk 13/18, size: 524288" uri="spotify:track:1ZlG9VQSUfSw0gJBzy7eEV" May 25 16:25:34 volumio volumio[874]: info: CoreCommandRouter::volumioGetVisibleSources May 25 16:25:34 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 25 16:25:34 volumio volumio[874]: info: CoreCommandRouter::volumioGetQueue May 25 16:25:34 volumio volumio[874]: info: CoreStateMachine::getQueue May 25 16:25:34 volumio volumio[874]: info: CorePlayQueue::getQueue May 25 16:25:34 volumio volumio[874]: info: Listing playlists May 25 16:25:38 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 25 16:25:38 volumio volumio[874]: info: In handleBrowseUri, curUri=spotify May 25 16:25:38 volumio volumio[874]: info: Preload queue cleared May 25 16:25:38 volumio volumio[874]: info: Preload queue cleared May 25 16:25:38 volumio volumio[874]: info: Preload queue cleared May 25 16:25:38 volumio volumio[874]: info: Preload queue cleared May 25 16:25:41 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 25 16:25:41 volumio volumio[874]: info: In handleBrowseUri, curUri=spotify/myalbums May 25 16:25:41 volumio volumio[874]: info: Preload queue cleared May 25 16:25:43 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 25 16:25:43 volumio volumio[874]: info: In handleBrowseUri, curUri=spotify:album:6behht7b5iDD8CRpTWMWrI May 25 16:25:43 volumio volumio[874]: info: Preload queue cleared May 25 16:25:43 volumio volumio[874]: info: Preloading song: spotify:track:5EWPzyWm0b9McPS5Qyaijp May 25 16:25:43 volumio volumio[874]: info: Preloading song: spotify:track:7kWxqtRVKmeEO77gzlTCwe May 25 16:25:43 volumio volumio[874]: info: Preloading song: spotify:track:2xYFPnvtSk2BCr8FH4SqlP May 25 16:25:43 volumio volumio[874]: info: Preloading song: spotify:track:1X7TuTJ1qByufKwkHsAGVo May 25 16:25:43 volumio volumio[874]: info: Preloading song: spotify:track:0NL1S7rhPMH7VkB9BAno8k May 25 16:25:43 volumio volumio[874]: info: Preloading song: spotify:track:088pUncVCYOih73qAotk2F May 25 16:25:43 volumio volumio[874]: info: Exploding uri spotify:track:5EWPzyWm0b9McPS5Qyaijp in service spop May 25 16:25:43 volumio volumio[874]: SPOTIFY: EXPLODING URI:spotify:track:5EWPzyWm0b9McPS5Qyaijp May 25 16:25:43 volumio volumio[874]: info: Exploding uri spotify:track:7kWxqtRVKmeEO77gzlTCwe in service spop May 25 16:25:43 volumio volumio[874]: SPOTIFY: EXPLODING URI:spotify:track:7kWxqtRVKmeEO77gzlTCwe May 25 16:25:43 volumio volumio[874]: info: Exploding uri spotify:track:2xYFPnvtSk2BCr8FH4SqlP in service spop May 25 16:25:43 volumio volumio[874]: SPOTIFY: EXPLODING URI:spotify:track:2xYFPnvtSk2BCr8FH4SqlP May 25 16:25:43 volumio volumio[874]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","service":"spop","name":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","type":"song","duration":165,"albumart":"https://i.scdn.co/image/ab67616d0000b2737ad9ace90779b3c83fc422ee","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 25 16:25:43 volumio volumio[874]: info: Exploding uri spotify:track:1X7TuTJ1qByufKwkHsAGVo in service spop May 25 16:25:43 volumio volumio[874]: SPOTIFY: EXPLODING URI:spotify:track:1X7TuTJ1qByufKwkHsAGVo May 25 16:25:43 volumio volumio[874]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7kWxqtRVKmeEO77gzlTCwe","service":"spop","name":"Lolita","artist":"Pierre de Maere","album":"Un jour, je","type":"song","duration":175,"albumart":"https://i.scdn.co/image/ab67616d0000b2737ad9ace90779b3c83fc422ee","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 25 16:25:43 volumio volumio[874]: info: Exploding uri spotify:track:0NL1S7rhPMH7VkB9BAno8k in service spop May 25 16:25:43 volumio volumio[874]: SPOTIFY: EXPLODING URI:spotify:track:0NL1S7rhPMH7VkB9BAno8k May 25 16:25:43 volumio volumio[874]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2xYFPnvtSk2BCr8FH4SqlP","service":"spop","name":"Menteur","artist":"Pierre de Maere","album":"Un jour, je","type":"song","duration":169,"albumart":"https://i.scdn.co/image/ab67616d0000b2737ad9ace90779b3c83fc422ee","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 25 16:25:43 volumio volumio[874]: info: Exploding uri spotify:track:088pUncVCYOih73qAotk2F in service spop May 25 16:25:43 volumio volumio[874]: SPOTIFY: EXPLODING URI:spotify:track:088pUncVCYOih73qAotk2F May 25 16:25:44 volumio volumio[874]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1X7TuTJ1qByufKwkHsAGVo","service":"spop","name":"J'aime, J'aime","artist":"Pierre de Maere","album":"Un jour, je","type":"song","duration":187,"albumart":"https://i.scdn.co/image/ab67616d0000b2737ad9ace90779b3c83fc422ee","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 25 16:25:44 volumio volumio[874]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0NL1S7rhPMH7VkB9BAno8k","service":"spop","name":"Regrets","artist":"Pierre de Maere","album":"Un jour, je","type":"song","duration":196,"albumart":"https://i.scdn.co/image/ab67616d0000b2737ad9ace90779b3c83fc422ee","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 25 16:25:44 volumio volumio[874]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:088pUncVCYOih73qAotk2F","service":"spop","name":"Lolita - Version piano - Bonus","artist":"Pierre de Maere","album":"Un jour, je","type":"song","duration":169,"albumart":"https://i.scdn.co/image/ab67616d0000b2737ad9ace90779b3c83fc422ee","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 25 16:25:45 volumio ntpd[2090]: 192.162.70.70 local addr 192.168.1.125 -> May 25 16:25:45 volumio go-librespot[3666]: time="2025-05-25T16:25:45+02:00" level=debug msg="fetched chunk 14/18, size: 524288" uri="spotify:track:1ZlG9VQSUfSw0gJBzy7eEV" May 25 16:25:45 volumio volumio[874]: info: Preload queue cleared May 25 16:25:45 volumio volumio[874]: info: CoreCommandRouter::volumioReplaceandPlayItems May 25 16:25:45 volumio volumio[874]: info: CoreStateMachine::ClearQueue May 25 16:25:45 volumio volumio[874]: info: CoreStateMachine::stop May 25 16:25:45 volumio volumio[874]: info: CoreStateMachine::serviceStop May 25 16:25:45 volumio volumio[874]: info: CoreCommandRouter::serviceStop May 25 16:25:45 volumio volumio[874]: info: Spotify Stop May 25 16:25:45 volumio volumio[874]: SPOTIFY: SPOTIFY STOP May 25 16:25:45 volumio volumio[874]: SPOTIFY: {"status":"play","title":"La pêche à la ligne","artist":"Renaud","album":"Mistral gagnant","albumart":"https://i.scdn.co/image/ab67616d00001e02dd3a17393ca3f47e4c523c26","uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","trackType":"spotify","codec":"ogg","seek":109031,"duration":214,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":27,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} May 25 16:25:45 volumio volumio[874]: info: Sending Spotify command to local API: /player/pause May 25 16:25:45 volumio volumio[874]: info: CorePlayQueue::clearPlayQueue May 25 16:25:45 volumio volumio[874]: info: CorePlayQueue::saveQueue May 25 16:25:45 volumio volumio[874]: info: CoreCommandRouter::volumioPushQueue May 25 16:25:45 volumio volumio[874]: info: CoreStateMachine::addQueueItems May 25 16:25:45 volumio volumio[874]: info: CorePlayQueue::addQueueItems May 25 16:25:45 volumio volumio[874]: info: Preload queue cleared May 25 16:25:45 volumio volumio[874]: info: Adding Item to queue: spotify:album:6behht7b5iDD8CRpTWMWrI May 25 16:25:45 volumio volumio[874]: info: Exploding uri spotify:album:6behht7b5iDD8CRpTWMWrI in service spop May 25 16:25:45 volumio volumio[874]: SPOTIFY: EXPLODING URI:spotify:album:6behht7b5iDD8CRpTWMWrI May 25 16:25:45 volumio go-librespot[3666]: time="2025-05-25T16:25:45+02:00" level=debug msg="pause track at 126834ms" May 25 16:25:45 volumio go-librespot[3666]: time="2025-05-25T16:25:45+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 25 16:25:45 volumio go-librespot[3666]: time="2025-05-25T16:25:45+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 25 16:25:45 volumio go-librespot[3666]: time="2025-05-25T16:25:45+02:00" level=trace msg="emitting websocket event: paused" May 25 16:25:45 volumio volumio[874]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","play_origin":"playlist"}} May 25 16:25:45 volumio volumio[874]: SPOTIFY: PUSH STATE SPOTIFY May 25 16:25:45 volumio volumio[874]: SPOTIFY: {"status":"pause","service":"spop","title":"La pêche à la ligne","artist":"Renaud","album":"Mistral gagnant","albumart":"https://i.scdn.co/image/ab67616d00001e02dd3a17393ca3f47e4c523c26","uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","trackType":"spotify","seek":127031,"duration":214,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 25 16:25:45 volumio volumio[874]: info: CoreCommandRouter::servicePushState May 25 16:25:45 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:45 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 25 16:25:45 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:45 volumio volumio[874]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","play_origin":"playlist"}} May 25 16:25:45 volumio volumio[874]: SPOTIFY: PUSH STATE SPOTIFY May 25 16:25:45 volumio volumio[874]: SPOTIFY: {"status":"pause","service":"spop","title":"La pêche à la ligne","artist":"Renaud","album":"Mistral gagnant","albumart":"https://i.scdn.co/image/ab67616d00001e02dd3a17393ca3f47e4c523c26","uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","trackType":"spotify","seek":127031,"duration":214,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 25 16:25:45 volumio volumio[874]: info: CoreCommandRouter::servicePushState May 25 16:25:45 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:45 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:45 volumio volumio[874]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","play_origin":"playlist"}} May 25 16:25:45 volumio volumio[874]: SPOTIFY: PUSH STATE SPOTIFY May 25 16:25:45 volumio volumio[874]: SPOTIFY: {"status":"pause","service":"spop","title":"La pêche à la ligne","artist":"Renaud","album":"Mistral gagnant","albumart":"https://i.scdn.co/image/ab67616d00001e02dd3a17393ca3f47e4c523c26","uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","trackType":"spotify","seek":127031,"duration":214,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 25 16:25:45 volumio volumio[874]: info: CoreCommandRouter::servicePushState May 25 16:25:45 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:45 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:45 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:45 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:45 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::volumioPushQueue May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::saveQueue May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::updateTrackBlock May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrackBlock May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::volumioPlay May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::play index 0 May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::setConsumeUpdateService undefined May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::stop May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::setConsumeUpdateService undefined May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::updateTrackBlock May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrackBlock May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::stPlaybackTimer May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::serviceStop May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::serviceStop May 25 16:25:46 volumio volumio[874]: info: Spotify Stop May 25 16:25:46 volumio volumio[874]: SPOTIFY: SPOTIFY STOP May 25 16:25:46 volumio volumio[874]: SPOTIFY: {"status":"pause","title":"La pêche à la ligne","artist":"Renaud","album":"Mistral gagnant","albumart":"https://i.scdn.co/image/ab67616d00001e02dd3a17393ca3f47e4c523c26","uri":"spotify:track:1ZlG9VQSUfSw0gJBzy7eEV","trackType":"spotify","codec":"ogg","seek":127031,"duration":214,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":27,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} May 25 16:25:46 volumio volumio[874]: info: Sending Spotify command to local API: /player/pause May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::play index undefined May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::setConsumeUpdateService undefined May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::startPlaybackTimer May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: info: [1748183146031] ControllerSpotify::clearAddPlayTrack May 25 16:25:46 volumio volumio[874]: info: Sending Spotify command with payload to local API: /player/play May 25 16:25:46 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=debug msg="pause track at 127300ms" May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=debug msg="resolved context of track" uri="spotify:track:5EWPzyWm0b9McPS5Qyaijp" May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:5EWPzyWm0b9McPS5Qyaijp" May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=debug msg="shuffled context with seed 3686278960306302618 (len: 1, keep: -1)" uri="spotify:track:5EWPzyWm0b9McPS5Qyaijp" May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:5EWPzyWm0b9McPS5Qyaijp" May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=trace msg="emitting websocket event: will_play" May 25 16:25:46 volumio volumio[874]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","play_origin":"go-librespot"}} May 25 16:25:46 volumio volumio[874]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","play_origin":"go-librespot"}} May 25 16:25:46 volumio volumio[874]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","play_origin":"go-librespot"}} May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=debug msg="selected format OGG_VORBIS_320 (44b12675ea4df0c8ca15e9827d25404654c9a6e1)" uri="spotify:track:5EWPzyWm0b9McPS5Qyaijp" May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=debug msg="requested aes key for file 44b12675ea4df0c8ca15e9827d25404654c9a6e1, gid: 5EWPzyWm0b9McPS5Qyaijp" May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=debug msg="fetched first chunk of 13, total size is 6335684 bytes" uri="spotify:track:5EWPzyWm0b9McPS5Qyaijp" May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames" May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=info msg="loaded track \"Un jour je marierai un ange\" (paused: false, position: 0ms, duration: 165557ms, prefetched: false)" uri="spotify:track:5EWPzyWm0b9McPS5Qyaijp" May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=trace msg="scheduling prefetch in 135s" May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=trace msg="emitting websocket event: metadata" May 25 16:25:46 volumio volumio[874]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","name":"Un jour je marierai un ange","artist_names":["Pierre de Maere"],"album_name":"Un jour, je","album_cover_url":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","position":0,"duration":165557,"release_date":"year:2022 month:1 day:21","track_number":1,"disc_number":1}} May 25 16:25:46 volumio volumio[874]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","name":"Un jour je marierai un ange","artist_names":["Pierre de Maere"],"album_name":"Un jour, je","album_cover_url":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","position":0,"duration":165557,"release_date":"year:2022 month:1 day:21","track_number":1,"disc_number":1}} May 25 16:25:46 volumio volumio[874]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","name":"Un jour je marierai un ange","artist_names":["Pierre de Maere"],"album_name":"Un jour, je","album_cover_url":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","position":0,"duration":165557,"release_date":"year:2022 month:1 day:21","track_number":1,"disc_number":1}} May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=debug msg="fetched chunk 1/12, size: 524288" uri="spotify:track:5EWPzyWm0b9McPS5Qyaijp" May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=debug msg="fetched chunk 3/12, size: 524288" uri="spotify:track:5EWPzyWm0b9McPS5Qyaijp" May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=trace msg="emitting websocket event: paused" May 25 16:25:46 volumio volumio[874]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","play_origin":"go-librespot"}} May 25 16:25:46 volumio volumio[874]: SPOTIFY: PUSH STATE SPOTIFY May 25 16:25:46 volumio volumio[874]: SPOTIFY: {"status":"pause","service":"spop","title":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","albumart":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::servicePushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","albumart":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 25 16:25:46 volumio volumio[874]: verbose: CURRENT POSITION 0 May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::syncState stateService pause May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::syncState currentStatus stop May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:46 volumio volumio[874]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","play_origin":"go-librespot"}} May 25 16:25:46 volumio volumio[874]: SPOTIFY: PUSH STATE SPOTIFY May 25 16:25:46 volumio volumio[874]: SPOTIFY: {"status":"pause","service":"spop","title":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","albumart":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::servicePushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","albumart":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 25 16:25:46 volumio volumio[874]: verbose: CURRENT POSITION 0 May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::syncState stateService pause May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::syncState currentStatus stop May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:46 volumio volumio[874]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","play_origin":"go-librespot"}} May 25 16:25:46 volumio volumio[874]: SPOTIFY: PUSH STATE SPOTIFY May 25 16:25:46 volumio volumio[874]: SPOTIFY: {"status":"pause","service":"spop","title":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","albumart":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::servicePushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","albumart":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 25 16:25:46 volumio volumio[874]: verbose: CURRENT POSITION 0 May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::syncState stateService pause May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::syncState currentStatus stop May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=trace msg="emitting websocket event: playing" May 25 16:25:46 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:46 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:46 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:46 volumio volumio[874]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","play_origin":"go-librespot"}} May 25 16:25:46 volumio volumio[874]: SPOTIFY: PUSH STATE SPOTIFY May 25 16:25:46 volumio volumio[874]: SPOTIFY: {"status":"play","service":"spop","title":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","albumart":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::servicePushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","albumart":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 25 16:25:46 volumio volumio[874]: verbose: CURRENT POSITION 0 May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::syncState stateService play May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::syncState currentStatus stop May 25 16:25:46 volumio volumio[874]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","play_origin":"go-librespot"}} May 25 16:25:46 volumio volumio[874]: SPOTIFY: PUSH STATE SPOTIFY May 25 16:25:46 volumio volumio[874]: SPOTIFY: {"status":"play","service":"spop","title":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","albumart":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::servicePushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","albumart":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=debug msg="fetched chunk 2/12, size: 524288" uri="spotify:track:5EWPzyWm0b9McPS5Qyaijp" May 25 16:25:46 volumio volumio[874]: verbose: CURRENT POSITION 0 May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::syncState stateService play May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::syncState currentStatus play May 25 16:25:46 volumio volumio[874]: info: Received an update from plugin. extracting info from payload May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:46 volumio volumio[874]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","play_origin":"go-librespot"}} May 25 16:25:46 volumio volumio[874]: SPOTIFY: PUSH STATE SPOTIFY May 25 16:25:46 volumio volumio[874]: SPOTIFY: {"status":"play","service":"spop","title":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","albumart":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::servicePushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","albumart":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 25 16:25:46 volumio volumio[874]: verbose: CURRENT POSITION 0 May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::syncState stateService play May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::syncState currentStatus play May 25 16:25:46 volumio volumio[874]: info: Received an update from plugin. extracting info from payload May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:46 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:46 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:46 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:46 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=debug msg="skipping dealer message" uri=playback-settings/content-settings-update May 25 16:25:46 volumio go-librespot[3666]: time="2025-05-25T16:25:46+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 159" May 25 16:25:46 volumio volumio[874]: SPOTIFY: PUSH STATE SPOTIFY May 25 16:25:46 volumio volumio[874]: SPOTIFY: {"status":"play","service":"spop","title":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","albumart":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::servicePushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","albumart":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 25 16:25:46 volumio volumio[874]: verbose: CURRENT POSITION 0 May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::syncState stateService play May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::syncState currentStatus play May 25 16:25:46 volumio volumio[874]: info: Received an update from plugin. extracting info from payload May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:46 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:46 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:46 volumio volumio[874]: SPOTIFY: PUSH STATE SPOTIFY May 25 16:25:46 volumio volumio[874]: SPOTIFY: {"status":"play","service":"spop","title":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","albumart":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::servicePushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","albumart":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 25 16:25:46 volumio volumio[874]: verbose: CURRENT POSITION 0 May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::syncState stateService play May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::syncState currentStatus play May 25 16:25:46 volumio volumio[874]: info: Received an update from plugin. extracting info from payload May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:46 volumio volumio[874]: SPOTIFY: PUSH STATE SPOTIFY May 25 16:25:46 volumio volumio[874]: SPOTIFY: {"status":"play","service":"spop","title":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","albumart":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::servicePushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","albumart":"https://i.scdn.co/image/ab67616d00001e027ad9ace90779b3c83fc422ee","uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","trackType":"spotify","seek":0,"duration":165,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 25 16:25:46 volumio volumio[874]: verbose: CURRENT POSITION 0 May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::syncState stateService play May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::syncState currentStatus play May 25 16:25:46 volumio volumio[874]: info: Received an update from plugin. extracting info from payload May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:46 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:25:46 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:25:46 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:25:46 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:46 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:46 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:46 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:25:48 volumio go-librespot[3666]: time="2025-05-25T16:25:48+02:00" level=trace msg="sent dealer ping" May 25 16:25:48 volumio go-librespot[3666]: time="2025-05-25T16:25:48+02:00" level=trace msg="received dealer pong" May 25 16:25:59 volumio go-librespot[3666]: time="2025-05-25T16:25:59+02:00" level=debug msg="fetched chunk 4/12, size: 524288" uri="spotify:track:5EWPzyWm0b9McPS5Qyaijp" May 25 16:26:13 volumio go-librespot[3666]: time="2025-05-25T16:26:13+02:00" level=debug msg="fetched chunk 5/12, size: 524288" uri="spotify:track:5EWPzyWm0b9McPS5Qyaijp" May 25 16:26:18 volumio go-librespot[3666]: time="2025-05-25T16:26:18+02:00" level=trace msg="sent dealer ping" May 25 16:26:18 volumio go-librespot[3666]: time="2025-05-25T16:26:18+02:00" level=trace msg="received dealer pong" May 25 16:26:26 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 25 16:26:26 volumio volumio[874]: info: CURURI: music-library May 25 16:26:26 volumio volumio[874]: info: Preload queue cleared May 25 16:26:27 volumio go-librespot[3666]: time="2025-05-25T16:26:27+02:00" level=debug msg="fetched chunk 6/12, size: 524288" uri="spotify:track:5EWPzyWm0b9McPS5Qyaijp" May 25 16:26:28 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 25 16:26:28 volumio volumio[874]: info: CURURI: music-library/NAS May 25 16:26:29 volumio volumio[874]: info: Preload queue cleared May 25 16:26:30 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 25 16:26:30 volumio volumio[874]: info: CURURI: music-library/NAS/NAS May 25 16:26:31 volumio volumio[874]: info: Preload queue cleared May 25 16:26:32 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 25 16:26:32 volumio volumio[874]: info: CURURI: music-library/NAS/NAS/Musiques May 25 16:26:32 volumio volumio[874]: info: Preload queue cleared May 25 16:26:34 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 25 16:26:34 volumio volumio[874]: info: CURURI: music-library/NAS/NAS/Musiques/ELECTROGENE May 25 16:26:34 volumio volumio[874]: info: Preload queue cleared May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/03 - Marc Lavoine - Le parking des anges.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/Assez_NIAGARA.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/Jaivu_NIAGARA.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/Jeanne Mas - En Rouge Et Noir.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/Philippe Cataldo - Les divas du dancin.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/Plus fort.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/roxette-listen-to-your-heart.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/Vivre ou survivre.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/zazie-je-suis-un-homme.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/Rose Laurens - Africa.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/Gold - Ville de lumière.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/Marre de cette nana la.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/Sans Contrefacon.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/A cause des garçons - A cause des garç.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/Corinne Charby - Boule de flipper (198.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/Felix Gray - La gitane (1987).mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/Jean-Pierre Mader - Disparue (1984).mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/Julie Pietri - Eve lève toi (1986).mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/Babacar.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/patricia-kaas-ceux-qui-nont-rien.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/patricia-kaas-mon-mec-a-moi.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/veronique-sanson-rien-que-de-leau.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/Miss Maggie.mp3 May 25 16:26:34 volumio volumio[874]: info: Preloading song: music-library/NAS/NAS/Musiques/ELECTROGENE/Lio - Banana split (1979).mp3 May 25 16:26:34 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/03 - Marc Lavoine - Le parking des anges.mp3 in service mpd May 25 16:26:34 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=Marc%20Lavoine//extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2F03%20-%20Marc%20Lavoine%20-%20Le%20parking%20des%20anges.mp3&metadata=false May 25 16:26:34 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/03 - Marc Lavoine - Le parking des anges.mp3 May 25 16:26:34 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/Assez_NIAGARA.mp3 in service mpd May 25 16:26:34 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=//extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FAssez_NIAGARA.mp3&metadata=false May 25 16:26:34 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/Assez_NIAGARA.mp3 May 25 16:26:34 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/Jaivu_NIAGARA.mp3 in service mpd May 25 16:26:34 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=//extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FJaivu_NIAGARA.mp3&metadata=false May 25 16:26:34 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/Jaivu_NIAGARA.mp3 May 25 16:26:34 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/Jeanne Mas - En Rouge Et Noir.mp3 in service mpd May 25 16:26:34 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=Jeanne%20Mas//extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FJeanne%20Mas%20-%20En%20Rouge%20Et%20Noir.mp3&metadata=false May 25 16:26:34 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/Jeanne Mas - En Rouge Et Noir.mp3 May 25 16:26:34 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/Philippe Cataldo - Les divas du dancin.mp3 in service mpd May 25 16:26:34 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=Philippe%20Cataldo//extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FPhilippe%20Cataldo%20-%20Les%20divas%20du%20dancin.mp3&metadata=false May 25 16:26:34 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/Philippe Cataldo - Les divas du dancin.mp3 May 25 16:26:34 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/Plus fort.mp3 in service mpd May 25 16:26:34 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=//extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FPlus%20fort.mp3&metadata=false May 25 16:26:34 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/Plus fort.mp3 May 25 16:26:34 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/roxette-listen-to-your-heart.mp3 in service mpd May 25 16:26:34 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=Roxette//extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2Froxette-listen-to-your-heart.mp3&metadata=false May 25 16:26:34 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/roxette-listen-to-your-heart.mp3 May 25 16:26:34 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/Vivre ou survivre.mp3 in service mpd May 25 16:26:34 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=//extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FVivre%20ou%20survivre.mp3&metadata=false May 25 16:26:34 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/Vivre ou survivre.mp3 May 25 16:26:34 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/zazie-je-suis-un-homme.mp3 in service mpd May 25 16:26:34 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=Zazie//extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2Fzazie-je-suis-un-homme.mp3&metadata=false May 25 16:26:34 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/zazie-je-suis-un-homme.mp3 May 25 16:26:34 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/Rose Laurens - Africa.mp3 in service mpd May 25 16:26:34 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=Rose%20Laurens//extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FRose%20Laurens%20-%20Africa.mp3&metadata=false May 25 16:26:34 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/Rose Laurens - Africa.mp3 May 25 16:26:34 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/Gold - Ville de lumière.mp3 in service mpd May 25 16:26:34 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=//extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FGold%20-%20%20Ville%20de%20lumi%C3%A8re.mp3&metadata=false May 25 16:26:34 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/Gold - Ville de lumière.mp3 May 25 16:26:34 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/Marre de cette nana la.mp3 in service mpd May 25 16:26:34 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=Patrick%20Bruel/1986%20-%20Deux%20faces/extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FMarre%20de%20cette%20nana%20la.mp3&metadata=false May 25 16:26:34 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/Marre de cette nana la.mp3 May 25 16:26:34 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/Sans Contrefacon.mp3 in service mpd May 25 16:26:34 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=Mylene%20Farmer%20-%201988%20-%20Ainsi%20S/Ainsi%20Sois-Je/extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FSans%20Contrefacon.mp3&metadata=false May 25 16:26:34 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/Sans Contrefacon.mp3 May 25 16:26:34 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/A cause des garçons - A cause des garç.mp3 in service mpd May 25 16:26:34 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=A%20cause%20des%20gar%C3%A7ons/Ann%C3%A9es%2080/extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FA%20cause%20des%20gar%C3%A7ons%20-%20A%20cause%20des%20gar%C3%A7.mp3&metadata=false May 25 16:26:34 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/A cause des garçons - A cause des garç.mp3 May 25 16:26:35 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/Corinne Charby - Boule de flipper (198.mp3 in service mpd May 25 16:26:35 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=Corinne%20Charby/Ann%C3%A9es%2080/extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FCorinne%20Charby%20-%20Boule%20de%20flipper%20(198.mp3&metadata=false May 25 16:26:35 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/Corinne Charby - Boule de flipper (198.mp3 May 25 16:26:35 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/Felix Gray - La gitane (1987).mp3 in service mpd May 25 16:26:35 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=Felix%20Gray/Ann%C3%A9es%2080/extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FFelix%20Gray%20-%20La%20gitane%20(1987).mp3&metadata=false May 25 16:26:35 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/Felix Gray - La gitane (1987).mp3 May 25 16:26:35 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/Jean-Pierre Mader - Disparue (1984).mp3 in service mpd May 25 16:26:35 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=Jean-Pierre%20Mader/Ann%C3%A9es%2080/extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FJean-Pierre%20Mader%20-%20Disparue%20(1984).mp3&metadata=false May 25 16:26:35 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/Jean-Pierre Mader - Disparue (1984).mp3 May 25 16:26:35 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/Julie Pietri - Eve lève toi (1986).mp3 in service mpd May 25 16:26:35 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=Julie%20Pietri/Ann%C3%A9es%2080/extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FJulie%20Pietri%20-%20Eve%20l%C3%A8ve%20toi%20(1986).mp3&metadata=false May 25 16:26:35 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/Julie Pietri - Eve lève toi (1986).mp3 May 25 16:26:35 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/Babacar.mp3 in service mpd May 25 16:26:35 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=France%20Gall/Best%20Of%202/extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FBabacar.mp3&metadata=false May 25 16:26:35 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/Babacar.mp3 May 25 16:26:35 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/patricia-kaas-ceux-qui-nont-rien.mp3 in service mpd May 25 16:26:35 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=Patricia%20Kaas/Je%20Te%20Dis%20Vous/extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2Fpatricia-kaas-ceux-qui-nont-rien.mp3&metadata=false May 25 16:26:35 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/patricia-kaas-ceux-qui-nont-rien.mp3 May 25 16:26:35 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/patricia-kaas-mon-mec-a-moi.mp3 in service mpd May 25 16:26:35 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=Patricia%20Kaas/Rien%20ne%20s'arrte%20(1987%20-%202001)/extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2Fpatricia-kaas-mon-mec-a-moi.mp3&metadata=false May 25 16:26:35 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/patricia-kaas-mon-mec-a-moi.mp3 May 25 16:26:35 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/veronique-sanson-rien-que-de-leau.mp3 in service mpd May 25 16:26:35 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=Vronique%20Sanson/Rien%20que%20de%20l'eau/extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2Fveronique-sanson-rien-que-de-leau.mp3&metadata=false May 25 16:26:35 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/veronique-sanson-rien-que-de-leau.mp3 May 25 16:26:35 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/Miss Maggie.mp3 in service mpd May 25 16:26:35 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=Renaud/The%20very%20meilleur%20of%20Renaud/extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FMiss%20Maggie.mp3&metadata=false May 25 16:26:35 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/Miss Maggie.mp3 May 25 16:26:35 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/Lio - Banana split (1979).mp3 in service mpd May 25 16:26:35 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=Lio/Volume%203%20CD1/extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FLio%20-%20Banana%20split%20(1979).mp3&metadata=false May 25 16:26:35 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/Lio - Banana split (1979).mp3 May 25 16:26:35 volumio volumio[874]: info: Preload queue cleared May 25 16:26:35 volumio volumio[874]: info: CoreCommandRouter::volumioReplaceandPlayItems May 25 16:26:35 volumio volumio[874]: info: CoreStateMachine::ClearQueue May 25 16:26:35 volumio volumio[874]: info: CoreStateMachine::stop May 25 16:26:35 volumio volumio[874]: info: CoreStateMachine::setConsumeUpdateService undefined May 25 16:26:35 volumio volumio[874]: info: CoreStateMachine::stPlaybackTimer May 25 16:26:35 volumio volumio[874]: info: CoreStateMachine::updateTrackBlock May 25 16:26:35 volumio volumio[874]: info: CorePlayQueue::getTrackBlock May 25 16:26:35 volumio volumio[874]: info: CoreStateMachine::pushState May 25 16:26:35 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:26:35 volumio volumio[874]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 25 16:26:35 volumio volumio[874]: info: CoreCommandRouter::volumioPushState May 25 16:26:35 volumio volumio[874]: info: CoreStateMachine::serviceStop May 25 16:26:35 volumio volumio[874]: info: CorePlayQueue::getTrack 0 May 25 16:26:35 volumio volumio[874]: info: CoreCommandRouter::serviceStop May 25 16:26:35 volumio volumio[874]: info: Spotify Stop May 25 16:26:35 volumio volumio[874]: SPOTIFY: SPOTIFY STOP May 25 16:26:35 volumio volumio[874]: SPOTIFY: {"status":"play","position":0,"title":"Un jour je marierai un ange","artist":"Pierre de Maere","album":"Un jour, je","albumart":"https://i.scdn.co/image/ab67616d0000b2737ad9ace90779b3c83fc422ee","uri":"spotify:track:5EWPzyWm0b9McPS5Qyaijp","trackType":"spotify","codec":"ogg","seek":0,"duration":165,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":27,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} May 25 16:26:35 volumio volumio[874]: info: Sending Spotify command to local API: /player/pause May 25 16:26:35 volumio volumio[874]: info: CorePlayQueue::clearPlayQueue May 25 16:26:35 volumio volumio[874]: info: CorePlayQueue::saveQueue May 25 16:26:35 volumio volumio[874]: info: CoreCommandRouter::volumioPushQueue May 25 16:26:35 volumio volumio[874]: info: CoreStateMachine::addQueueItems May 25 16:26:35 volumio volumio[874]: info: CorePlayQueue::addQueueItems May 25 16:26:35 volumio volumio[874]: info: Preload queue cleared May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/03 - Marc Lavoine - Le parking des anges.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/03 - Marc Lavoine - Le parking des anges.mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/Assez_NIAGARA.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/Assez_NIAGARA.mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/Jaivu_NIAGARA.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/Jaivu_NIAGARA.mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/Jeanne Mas - En Rouge Et Noir.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/Jeanne Mas - En Rouge Et Noir.mp3 May 25 16:26:35 volumio volumio[874]: info: CoreCommandRouter::volumioPushQueue May 25 16:26:35 volumio volumio[874]: info: CorePlayQueue::saveQueue May 25 16:26:35 volumio volumio[874]: info: CoreStateMachine::updateTrackBlock May 25 16:26:35 volumio volumio[874]: info: CorePlayQueue::getTrackBlock May 25 16:26:35 volumio volumio[874]: info: CoreCommandRouter::volumioPlay May 25 16:26:35 volumio volumio[874]: info: CoreStateMachine::play index 3 May 25 16:26:35 volumio volumio[874]: info: CoreStateMachine::setConsumeUpdateService undefined May 25 16:26:35 volumio volumio[874]: info: CoreStateMachine::addQueueItems May 25 16:26:35 volumio volumio[874]: info: CorePlayQueue::addQueueItems May 25 16:26:35 volumio volumio[874]: info: Preload queue cleared May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/Philippe Cataldo - Les divas du dancin.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/Philippe Cataldo - Les divas du dancin.mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/Plus fort.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/Plus fort.mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/roxette-listen-to-your-heart.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/roxette-listen-to-your-heart.mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/Vivre ou survivre.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/Vivre ou survivre.mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/zazie-je-suis-un-homme.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/zazie-je-suis-un-homme.mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/Rose Laurens - Africa.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/Rose Laurens - Africa.mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/Gold - Ville de lumière.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/Gold - Ville de lumière.mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/Marre de cette nana la.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/Marre de cette nana la.mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/Sans Contrefacon.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/Sans Contrefacon.mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/A cause des garçons - A cause des garç.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/A cause des garçons - A cause des garç.mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/Corinne Charby - Boule de flipper (198.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/Corinne Charby - Boule de flipper (198.mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/Felix Gray - La gitane (1987).mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/Felix Gray - La gitane (1987).mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/Jean-Pierre Mader - Disparue (1984).mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/Jean-Pierre Mader - Disparue (1984).mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/Julie Pietri - Eve lève toi (1986).mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/Julie Pietri - Eve lève toi (1986).mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/Babacar.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/Babacar.mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/patricia-kaas-ceux-qui-nont-rien.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/patricia-kaas-ceux-qui-nont-rien.mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/patricia-kaas-mon-mec-a-moi.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/patricia-kaas-mon-mec-a-moi.mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/veronique-sanson-rien-que-de-leau.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/veronique-sanson-rien-que-de-leau.mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/Miss Maggie.mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/Miss Maggie.mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/Lio - Banana split (1979).mp3 May 25 16:26:35 volumio volumio[874]: info: Using cached record of: music-library/NAS/NAS/Musiques/ELECTROGENE/Lio - Banana split (1979).mp3 May 25 16:26:35 volumio volumio[874]: info: Adding Item to queue: music-library/NAS/NAS/Musiques/ELECTROGENE/ELECTROGENE.zip May 25 16:26:35 volumio volumio[874]: info: Exploding uri music-library/NAS/NAS/Musiques/ELECTROGENE/ELECTROGENE.zip in service mpd May 25 16:26:35 volumio volumio[874]: info: CoreStateMachine::stop May 25 16:26:35 volumio volumio[874]: info: CoreStateMachine::setConsumeUpdateService undefined May 25 16:26:35 volumio volumio[874]: info: CoreStateMachine::play index undefined May 25 16:26:35 volumio volumio[874]: info: CoreStateMachine::setConsumeUpdateService undefined May 25 16:26:35 volumio volumio[874]: info: CorePlayQueue::getTrack 3 May 25 16:26:35 volumio volumio[874]: info: CoreStateMachine::startPlaybackTimer May 25 16:26:35 volumio volumio[874]: info: CorePlayQueue::getTrack 3 May 25 16:26:35 volumio volumio[874]: verbose: ControllerMpd::clearAddPlayTracks NAS/NAS/Musiques/ELECTROGENE/Jeanne Mas - En Rouge Et Noir.mp3 May 25 16:26:35 volumio volumio[874]: verbose: ControllerMpd::sendMpdCommand stop May 25 16:26:35 volumio volumio[874]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 May 25 16:26:35 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=Marc%20Lavoine//extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FELECTROGENE.zip&metadata=false May 25 16:26:35 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/ELECTROGENE.zip May 25 16:26:35 volumio volumio[874]: info: ALBUMART /albumart?cacheid=606&web=//extralarge&path=%2Fmnt%2FNAS%2FNAS%2FMusiques%2FELECTROGENE%2FELECTROGENE.zip&metadata=false May 25 16:26:35 volumio volumio[874]: info: URI /mnt/NAS/NAS/Musiques/ELECTROGENE/ELECTROGENE.zip May 25 16:26:35 volumio volumio[874]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 25 16:26:35 volumio volumio[874]: Error: Unable to resolve or reject the same promise twice May 25 16:26:35 volumio volumio[874]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) May 25 16:26:35 volumio volumio[874]: at /volumio/app/plugins/music_service/mpd/index.js:2569:21 May 25 16:26:35 volumio volumio[874]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) May 25 16:26:35 volumio volumio[874]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) May 25 16:26:35 volumio volumio[874]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) May 25 16:26:35 volumio volumio[874]: at Socket.emit (events.js:400:28) May 25 16:26:35 volumio volumio[874]: at addChunk (internal/streams/readable.js:293:12) May 25 16:26:35 volumio volumio[874]: at readableAddChunk (internal/streams/readable.js:263:11) May 25 16:26:35 volumio volumio[874]: at Socket.Readable.push (internal/streams/readable.js:206:10) May 25 16:26:35 volumio volumio[874]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) May 25 16:26:35 volumio volumio[874]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 25 16:26:35 volumio sudo[3890]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-25 16:25 May 25 16:26:35 volumio sudo[3890]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:50:12 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="39b0f8c200b2dcadf117e189b4b3632d"