-- Logs begin at Sat 2024-09-07 22:17:11 EEST, end at Sat 2024-09-07 23:30:03 EEST. -- Sep 07 23:29:04 volumio go-librespot[2366]: time="2024-09-07T23:29:04+03:00" level=debug msg="fetched chunk 6/18, size: 524288" uri="spotify:track:60EXXuME5NO8t8F0SkUvn1" Sep 07 23:29:08 volumio volumio[903]: info: Preload queue cleared Sep 07 23:29:08 volumio volumio[903]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 07 23:29:08 volumio volumio[903]: info: CoreStateMachine::ClearQueue Sep 07 23:29:08 volumio volumio[903]: info: CoreStateMachine::stop Sep 07 23:29:08 volumio volumio[903]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 23:29:08 volumio volumio[903]: info: CoreStateMachine::stPlaybackTimer Sep 07 23:29:08 volumio volumio[903]: info: CoreStateMachine::updateTrackBlock Sep 07 23:29:08 volumio volumio[903]: info: CorePlayQueue::getTrackBlock Sep 07 23:29:08 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:08 volumio volumio[903]: info: CorePlayQueue::getTrack 3 Sep 07 23:29:08 volumio volumio[903]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 23:29:08 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:08 volumio volumio[903]: info: CoreStateMachine::serviceStop Sep 07 23:29:08 volumio volumio[903]: info: CorePlayQueue::getTrack 3 Sep 07 23:29:08 volumio volumio[903]: info: CoreCommandRouter::serviceStop Sep 07 23:29:08 volumio volumio[903]: info: Spotify Stop Sep 07 23:29:08 volumio volumio[903]: SPOTIFY: SPOTIFY STOP Sep 07 23:29:08 volumio volumio[903]: SPOTIFY: {"status":"play","position":3,"title":"Easy Like Sunday Morning","artist":"Saxophone Rufus","album":"Saxofone Romantico","albumart":"https://i.scdn.co/image/ab67616d0000b273b83e4f913bd4597f0090175a","uri":"spotify:track:60EXXuME5NO8t8F0SkUvn1","trackType":"spotify","codec":"ogg","seek":0,"duration":225,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":91,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Sep 07 23:29:08 volumio volumio[903]: info: Sending Spotify command to local API: /player/pause Sep 07 23:29:08 volumio volumio[903]: info: CorePlayQueue::clearPlayQueue Sep 07 23:29:08 volumio volumio[903]: info: CorePlayQueue::saveQueue Sep 07 23:29:08 volumio volumio[903]: info: CoreCommandRouter::volumioPushQueue Sep 07 23:29:08 volumio volumio[903]: info: CoreStateMachine::addQueueItems Sep 07 23:29:08 volumio volumio[903]: info: CorePlayQueue::addQueueItems Sep 07 23:29:08 volumio volumio[903]: info: Preload queue cleared Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:3m7jsBiMxam6FdxHUH5IWm Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:3m7jsBiMxam6FdxHUH5IWm Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:0Ckut00dWyBA4Gqdg3Cy6F Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:0Ckut00dWyBA4Gqdg3Cy6F Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:1iL5DwPJVa3b2TEJAHnreJ Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:1iL5DwPJVa3b2TEJAHnreJ Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:60EXXuME5NO8t8F0SkUvn1 Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:60EXXuME5NO8t8F0SkUvn1 Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:5Kflcwxjthdx4ABfr41ub8 Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:5Kflcwxjthdx4ABfr41ub8 Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:18OrnYJ4JJB5YODYP6bsly Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:18OrnYJ4JJB5YODYP6bsly Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:0TX3ylYLBKYBDv7RVcjwro Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:0TX3ylYLBKYBDv7RVcjwro Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:3QaHdolrs2FfCcnOe96jRB Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:3QaHdolrs2FfCcnOe96jRB Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:3x1W0QWwaTLgFjphimwCkM Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:3x1W0QWwaTLgFjphimwCkM Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:4g87drXuYFrWby45YCK1Ac Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:4g87drXuYFrWby45YCK1Ac Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:4ij0h1lRybCDRGBvEcAYwN Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:4ij0h1lRybCDRGBvEcAYwN Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:6nr526fDRzpwKFsl9UeKPe Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:6nr526fDRzpwKFsl9UeKPe Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:7a63wruWSmcvt4bHNXq8qi Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:7a63wruWSmcvt4bHNXq8qi Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:6cLqmPbErRgLZVY1Qf8pO1 Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:6cLqmPbErRgLZVY1Qf8pO1 Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:10GQFZd42RhcjEMKY6kDu6 Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:10GQFZd42RhcjEMKY6kDu6 Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:1T9L0k4ZxOhlRgx3SR8C42 Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:1T9L0k4ZxOhlRgx3SR8C42 Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:7FaSIlhdAVhM5GpoBut23A Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:7FaSIlhdAVhM5GpoBut23A Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:2wgd2LdI6VRXtLvJv4N34j Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:2wgd2LdI6VRXtLvJv4N34j Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:6ZqWnSvmi6u8f4FxEHyqH3 Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:6ZqWnSvmi6u8f4FxEHyqH3 Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:2rIObYzNjo15RqXKADsfCj Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:2rIObYzNjo15RqXKADsfCj Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:742xORxrc8mCcKkLTMY5W8 Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:742xORxrc8mCcKkLTMY5W8 Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:5wJO9xnIa0PTqKGfrz70H7 Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:5wJO9xnIa0PTqKGfrz70H7 Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:4LdgTEMnxlFbXqDNvnCqAW Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:4LdgTEMnxlFbXqDNvnCqAW Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:7ychhJCL8wdaDtUpMR6z3M Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:7ychhJCL8wdaDtUpMR6z3M Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:204z55ipM2WaXF2h4Ce8Ql Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:204z55ipM2WaXF2h4Ce8Ql Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:3imtlETzn51gH6v0AoDoud Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:3imtlETzn51gH6v0AoDoud Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:484WZZxRC7hBM5gDZOdQQy Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:484WZZxRC7hBM5gDZOdQQy Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:29cVdn9QH0CcfKLB2OuppS Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:29cVdn9QH0CcfKLB2OuppS Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:1rwhnruxWcovn37G6rWXyV Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:1rwhnruxWcovn37G6rWXyV Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:39z0Q92Hq4fL8gfeMLLzj5 Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:39z0Q92Hq4fL8gfeMLLzj5 Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:6x8SdF7t6LIXI0qXFd7Ge1 Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:6x8SdF7t6LIXI0qXFd7Ge1 Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:4D2Sh4IhWg5HPlRnI4iyzE Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:4D2Sh4IhWg5HPlRnI4iyzE Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:19dvP4cDJ0xtaZXUkNVJwi Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:19dvP4cDJ0xtaZXUkNVJwi Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:7ptnGvzu1WxowaLrf4sQZy Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:7ptnGvzu1WxowaLrf4sQZy Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:7lcQd1wBXSCIpOzI0oZb9h Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:7lcQd1wBXSCIpOzI0oZb9h Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:4zmaXq9a2gZ5l2ko0247xR Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:4zmaXq9a2gZ5l2ko0247xR Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:6Ys081wMm9uKoCMMZVU63S Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:6Ys081wMm9uKoCMMZVU63S Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:5Ekztt86kMO32saja9gT1j Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:5Ekztt86kMO32saja9gT1j Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:0yhaxHsepqgh6fgzYwedOu Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:0yhaxHsepqgh6fgzYwedOu Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:7nspwxKGUvwZQCu1Ctdu5m Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:7nspwxKGUvwZQCu1Ctdu5m Sep 07 23:29:08 volumio volumio[903]: info: Adding Item to queue: spotify:track:6PV0SXNxQlLFi6Y2CFMCkW Sep 07 23:29:08 volumio volumio[903]: info: Using cached record of: spotify:track:6PV0SXNxQlLFi6Y2CFMCkW Sep 07 23:29:08 volumio volumio[903]: info: CoreCommandRouter::volumioPushQueue Sep 07 23:29:08 volumio volumio[903]: info: CorePlayQueue::saveQueue Sep 07 23:29:08 volumio volumio[903]: info: CoreStateMachine::updateTrackBlock Sep 07 23:29:08 volumio volumio[903]: info: CorePlayQueue::getTrackBlock Sep 07 23:29:08 volumio volumio[903]: info: CoreCommandRouter::volumioPlay Sep 07 23:29:08 volumio volumio[903]: info: CoreStateMachine::play index 15 Sep 07 23:29:08 volumio volumio[903]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 23:29:08 volumio volumio[903]: info: CoreStateMachine::stop Sep 07 23:29:08 volumio volumio[903]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 23:29:08 volumio volumio[903]: info: CoreStateMachine::play index undefined Sep 07 23:29:08 volumio volumio[903]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 23:29:08 volumio volumio[903]: info: CorePlayQueue::getTrack 15 Sep 07 23:29:08 volumio volumio[903]: info: CoreStateMachine::startPlaybackTimer Sep 07 23:29:08 volumio volumio[903]: info: CorePlayQueue::getTrack 15 Sep 07 23:29:08 volumio volumio[903]: info: [1725740948853] ControllerSpotify::clearAddPlayTrack Sep 07 23:29:08 volumio volumio[903]: info: Sending Spotify command with payload to local API: /player/play Sep 07 23:29:08 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:08 volumio go-librespot[2366]: time="2024-09-07T23:29:08+03:00" level=debug msg="pause track at 41251ms" Sep 07 23:29:09 volumio go-librespot[2366]: time="2024-09-07T23:29:09+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:09 volumio go-librespot[2366]: time="2024-09-07T23:29:09+03:00" level=debug msg="resolved context of track" uri="spotify:track:1T9L0k4ZxOhlRgx3SR8C42" Sep 07 23:29:09 volumio go-librespot[2366]: time="2024-09-07T23:29:09+03:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1T9L0k4ZxOhlRgx3SR8C42" Sep 07 23:29:09 volumio go-librespot[2366]: time="2024-09-07T23:29:09+03:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1T9L0k4ZxOhlRgx3SR8C42" Sep 07 23:29:09 volumio go-librespot[2366]: time="2024-09-07T23:29:09+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:09 volumio go-librespot[2366]: time="2024-09-07T23:29:09+03:00" level=trace msg="emitting websocket event: will_play" Sep 07 23:29:09 volumio volumio[903]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","play_origin":"go-librespot"}} Sep 07 23:29:09 volumio volumio[903]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","play_origin":"go-librespot"}} Sep 07 23:29:09 volumio go-librespot[2366]: time="2024-09-07T23:29:09+03:00" level=debug msg="selected format OGG_VORBIS_320 (daa0433edc6908d39aa5b4e459f4f753643d4496)" uri="spotify:track:1T9L0k4ZxOhlRgx3SR8C42" Sep 07 23:29:09 volumio go-librespot[2366]: time="2024-09-07T23:29:09+03:00" level=debug msg="requested aes key for file daa0433edc6908d39aa5b4e459f4f753643d4496, gid: 1T9L0k4ZxOhlRgx3SR8C42" Sep 07 23:29:09 volumio go-librespot[2366]: time="2024-09-07T23:29:09+03:00" level=debug msg="fetched first chunk of 14, total size is 6851676 bytes" uri="spotify:track:1T9L0k4ZxOhlRgx3SR8C42" Sep 07 23:29:09 volumio go-librespot[2366]: time="2024-09-07T23:29:09+03:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:1T9L0k4ZxOhlRgx3SR8C42" Sep 07 23:29:09 volumio go-librespot[2366]: time="2024-09-07T23:29:09+03:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5011 us, period size = 221 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 99 frames" Sep 07 23:29:09 volumio go-librespot[2366]: time="2024-09-07T23:29:09+03:00" level=info msg="loaded track \"Savage Love\" (paused: false, position: 0ms, duration: 173494ms, prefetched: false)" uri="spotify:track:1T9L0k4ZxOhlRgx3SR8C42" Sep 07 23:29:09 volumio go-librespot[2366]: time="2024-09-07T23:29:09+03:00" level=debug msg="fetched chunk 1/13, size: 524288" uri="spotify:track:1T9L0k4ZxOhlRgx3SR8C42" Sep 07 23:29:10 volumio go-librespot[2366]: time="2024-09-07T23:29:10+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:10 volumio go-librespot[2366]: time="2024-09-07T23:29:10+03:00" level=trace msg="scheduling prefetch in 143s" Sep 07 23:29:10 volumio go-librespot[2366]: time="2024-09-07T23:29:10+03:00" level=trace msg="emitting websocket event: metadata" Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","name":"Savage Love","artist_names":["Joel Ferreira Sax"],"album_name":"Savage Love","album_cover_url":"https://i.scdn.co/image/ab67616d00001e021206163de04975137bc4e657","position":0,"duration":173494,"release_date":"year:2021 month:2 day:5","track_number":1,"disc_number":1}} Sep 07 23:29:10 volumio go-librespot[2366]: time="2024-09-07T23:29:10+03:00" level=debug msg="fetched chunk 2/13, size: 524288" uri="spotify:track:1T9L0k4ZxOhlRgx3SR8C42" Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","name":"Savage Love","artist_names":["Joel Ferreira Sax"],"album_name":"Savage Love","album_cover_url":"https://i.scdn.co/image/ab67616d00001e021206163de04975137bc4e657","position":0,"duration":173494,"release_date":"year:2021 month:2 day:5","track_number":1,"disc_number":1}} Sep 07 23:29:10 volumio go-librespot[2366]: time="2024-09-07T23:29:10+03:00" level=debug msg="fetched chunk 3/13, size: 524288" uri="spotify:track:1T9L0k4ZxOhlRgx3SR8C42" Sep 07 23:29:10 volumio go-librespot[2366]: time="2024-09-07T23:29:10+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:10 volumio go-librespot[2366]: time="2024-09-07T23:29:10+03:00" level=trace msg="emitting websocket event: paused" Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","play_origin":"go-librespot"}} Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: {"status":"pause","service":"spop","title":"Savage Love","artist":"Joel Ferreira Sax","album":"Savage Love","albumart":"https://i.scdn.co/image/ab67616d00001e021206163de04975137bc4e657","uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","trackType":"spotify","seek":0,"duration":173,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:10 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:10 volumio volumio[903]: info: CorePlayQueue::getTrack 15 Sep 07 23:29:10 volumio volumio[903]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Savage Love","artist":"Joel Ferreira Sax","album":"Savage Love","albumart":"https://i.scdn.co/image/ab67616d00001e021206163de04975137bc4e657","uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","trackType":"spotify","seek":0,"duration":173,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:10 volumio volumio[903]: verbose: CURRENT POSITION 15 Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::syncState stateService pause Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus stop Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:10 volumio volumio[903]: info: CorePlayQueue::getTrack 15 Sep 07 23:29:10 volumio volumio[903]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 23:29:10 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","play_origin":"go-librespot"}} Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: {"status":"pause","service":"spop","title":"Savage Love","artist":"Joel Ferreira Sax","album":"Savage Love","albumart":"https://i.scdn.co/image/ab67616d00001e021206163de04975137bc4e657","uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","trackType":"spotify","seek":0,"duration":173,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:10 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:10 volumio volumio[903]: info: CorePlayQueue::getTrack 15 Sep 07 23:29:10 volumio volumio[903]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Savage Love","artist":"Joel Ferreira Sax","album":"Savage Love","albumart":"https://i.scdn.co/image/ab67616d00001e021206163de04975137bc4e657","uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","trackType":"spotify","seek":0,"duration":173,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:10 volumio volumio[903]: verbose: CURRENT POSITION 15 Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::syncState stateService pause Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus stop Sep 07 23:29:10 volumio go-librespot[2366]: time="2024-09-07T23:29:10+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:10 volumio go-librespot[2366]: time="2024-09-07T23:29:10+03:00" level=trace msg="emitting websocket event: playing" Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:10 volumio volumio[903]: info: CorePlayQueue::getTrack 15 Sep 07 23:29:10 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","play_origin":"go-librespot"}} Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: {"status":"play","service":"spop","title":"Savage Love","artist":"Joel Ferreira Sax","album":"Savage Love","albumart":"https://i.scdn.co/image/ab67616d00001e021206163de04975137bc4e657","uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","trackType":"spotify","seek":0,"duration":173,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:10 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:10 volumio volumio[903]: info: CorePlayQueue::getTrack 15 Sep 07 23:29:10 volumio volumio[903]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Savage Love","artist":"Joel Ferreira Sax","album":"Savage Love","albumart":"https://i.scdn.co/image/ab67616d00001e021206163de04975137bc4e657","uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","trackType":"spotify","seek":0,"duration":173,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:10 volumio volumio[903]: verbose: CURRENT POSITION 15 Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::syncState stateService play Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus stop Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","play_origin":"go-librespot"}} Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: {"status":"play","service":"spop","title":"Savage Love","artist":"Joel Ferreira Sax","album":"Savage Love","albumart":"https://i.scdn.co/image/ab67616d00001e021206163de04975137bc4e657","uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","trackType":"spotify","seek":0,"duration":173,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:10 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:10 volumio volumio[903]: info: CorePlayQueue::getTrack 15 Sep 07 23:29:10 volumio volumio[903]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Savage Love","artist":"Joel Ferreira Sax","album":"Savage Love","albumart":"https://i.scdn.co/image/ab67616d00001e021206163de04975137bc4e657","uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","trackType":"spotify","seek":0,"duration":173,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:10 volumio volumio[903]: verbose: CURRENT POSITION 15 Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::syncState stateService play Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus play Sep 07 23:29:10 volumio volumio[903]: info: Received an update from plugin. extracting info from payload Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:10 volumio volumio[903]: info: CorePlayQueue::getTrack 15 Sep 07 23:29:10 volumio volumio[903]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 23:29:10 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:10 volumio volumio[903]: info: CorePlayQueue::getTrack 15 Sep 07 23:29:10 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: {"status":"play","service":"spop","title":"Savage Love","artist":"Joel Ferreira Sax","album":"Savage Love","albumart":"https://i.scdn.co/image/ab67616d00001e021206163de04975137bc4e657","uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","trackType":"spotify","seek":0,"duration":173,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:10 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:10 volumio volumio[903]: info: CorePlayQueue::getTrack 15 Sep 07 23:29:10 volumio volumio[903]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Savage Love","artist":"Joel Ferreira Sax","album":"Savage Love","albumart":"https://i.scdn.co/image/ab67616d00001e021206163de04975137bc4e657","uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","trackType":"spotify","seek":0,"duration":173,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:10 volumio volumio[903]: verbose: CURRENT POSITION 15 Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::syncState stateService play Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus play Sep 07 23:29:10 volumio volumio[903]: info: Received an update from plugin. extracting info from payload Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:10 volumio volumio[903]: info: CorePlayQueue::getTrack 15 Sep 07 23:29:10 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:10 volumio volumio[903]: info: CorePlayQueue::getTrack 15 Sep 07 23:29:10 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:10 volumio volumio[903]: SPOTIFY: {"status":"play","service":"spop","title":"Savage Love","artist":"Joel Ferreira Sax","album":"Savage Love","albumart":"https://i.scdn.co/image/ab67616d00001e021206163de04975137bc4e657","uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","trackType":"spotify","seek":0,"duration":173,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:10 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:10 volumio volumio[903]: info: CorePlayQueue::getTrack 15 Sep 07 23:29:10 volumio volumio[903]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Savage Love","artist":"Joel Ferreira Sax","album":"Savage Love","albumart":"https://i.scdn.co/image/ab67616d00001e021206163de04975137bc4e657","uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","trackType":"spotify","seek":0,"duration":173,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:10 volumio volumio[903]: verbose: CURRENT POSITION 15 Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::syncState stateService play Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus play Sep 07 23:29:10 volumio volumio[903]: info: Received an update from plugin. extracting info from payload Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:10 volumio volumio[903]: info: CorePlayQueue::getTrack 15 Sep 07 23:29:10 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:10 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:10 volumio volumio[903]: info: CorePlayQueue::getTrack 15 Sep 07 23:29:10 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:11 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:11 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:16 volumio ntpd[2126]: ntpd exiting on signal 15 (Terminated) Sep 07 23:29:16 volumio systemd[1]: Stopping Network Time Service... Sep 07 23:29:16 volumio ntpd[2126]: 162.159.200.1 local addr 192.168.0.188 -> Sep 07 23:29:16 volumio systemd[1]: ntp.service: Succeeded. Sep 07 23:29:16 volumio ntpd[2126]: 37.53.71.213 local addr 192.168.0.188 -> Sep 07 23:29:16 volumio systemd[1]: Stopped Network Time Service. Sep 07 23:29:16 volumio ntpd[2126]: 91.210.190.13 local addr 192.168.0.188 -> Sep 07 23:29:16 volumio ntpd[2126]: 91.236.251.13 local addr 192.168.0.188 -> Sep 07 23:29:16 volumio ntpd[2126]: 91.236.251.234 local addr 192.168.0.188 -> Sep 07 23:29:16 volumio ntpd[2126]: 162.159.200.123 local addr 192.168.0.188 -> Sep 07 23:29:16 volumio ntpd[2126]: 37.53.92.252 local addr 192.168.0.188 -> Sep 07 23:29:16 volumio ntpd[2126]: 91.236.251.35 local addr 192.168.0.188 -> Sep 07 23:29:16 volumio ntpd[2126]: 91.236.251.34 local addr 192.168.0.188 -> Sep 07 23:29:16 volumio ntpd[2126]: 91.236.251.31 local addr 192.168.0.188 -> Sep 07 23:29:16 volumio ntpd[2126]: 193.106.144.13 local addr 192.168.0.188 -> Sep 07 23:29:16 volumio ntpd[2126]: 176.114.2.114 local addr 192.168.0.188 -> Sep 07 23:29:16 volumio ntpd[2126]: 37.53.80.127 local addr 192.168.0.188 -> Sep 07 23:29:16 volumio ntpd[2126]: 193.106.144.6 local addr 192.168.0.188 -> Sep 07 23:29:16 volumio ntpd[2126]: 217.12.206.12 local addr 192.168.0.188 -> Sep 07 23:29:16 volumio ntpd[2126]: 213.231.2.124 local addr 192.168.0.188 -> Sep 07 23:29:16 volumio systemd[1]: Starting Network Time Service... Sep 07 23:29:16 volumio ntpd[2689]: ntpd 4.2.8p12@1.3728-o (1): Starting Sep 07 23:29:16 volumio ntpd[2689]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Sep 07 23:29:16 volumio systemd[1]: Started Network Time Service. Sep 07 23:29:16 volumio ntpd[2696]: proto: precision = 0.442 usec (-21) Sep 07 23:29:16 volumio ntpd[2696]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Sep 07 23:29:16 volumio ntpd[2696]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Sep 07 23:29:16 volumio ntpd[2696]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 620 days ago Sep 07 23:29:16 volumio ntpd[2696]: Listen and drop on 0 v6wildcard [::]:123 Sep 07 23:29:16 volumio ntpd[2696]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Sep 07 23:29:16 volumio ntpd[2696]: Listen normally on 2 lo 127.0.0.1:123 Sep 07 23:29:16 volumio ntpd[2696]: Listen normally on 3 eth0 192.168.0.188:123 Sep 07 23:29:16 volumio ntpd[2696]: Listen normally on 4 wlan0 192.168.211.1:123 Sep 07 23:29:16 volumio ntpd[2696]: Listen normally on 5 wlan0 169.254.205.172:123 Sep 07 23:29:16 volumio ntpd[2696]: Listening on routing socket on fd #22 for interface updates Sep 07 23:29:16 volumio ntpd[2696]: kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized Sep 07 23:29:16 volumio ntpd[2696]: kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized Sep 07 23:29:17 volumio ntpd[2696]: Soliciting pool server 31.28.161.71 Sep 07 23:29:18 volumio volumio[903]: info: Preload queue cleared Sep 07 23:29:18 volumio volumio[903]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 07 23:29:18 volumio volumio[903]: info: CoreStateMachine::ClearQueue Sep 07 23:29:18 volumio volumio[903]: info: CoreStateMachine::stop Sep 07 23:29:18 volumio volumio[903]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 23:29:18 volumio volumio[903]: info: CoreStateMachine::stPlaybackTimer Sep 07 23:29:18 volumio volumio[903]: info: CoreStateMachine::updateTrackBlock Sep 07 23:29:18 volumio volumio[903]: info: CorePlayQueue::getTrackBlock Sep 07 23:29:18 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:18 volumio volumio[903]: info: CorePlayQueue::getTrack 15 Sep 07 23:29:18 volumio volumio[903]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 23:29:18 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:18 volumio volumio[903]: info: CoreStateMachine::serviceStop Sep 07 23:29:18 volumio volumio[903]: info: CorePlayQueue::getTrack 15 Sep 07 23:29:18 volumio volumio[903]: info: CoreCommandRouter::serviceStop Sep 07 23:29:18 volumio volumio[903]: info: Spotify Stop Sep 07 23:29:18 volumio volumio[903]: SPOTIFY: SPOTIFY STOP Sep 07 23:29:18 volumio volumio[903]: SPOTIFY: {"status":"play","position":15,"title":"Savage Love","artist":"Joel Ferreira Sax","album":"Savage Love","albumart":"https://i.scdn.co/image/ab67616d0000b2731206163de04975137bc4e657","uri":"spotify:track:1T9L0k4ZxOhlRgx3SR8C42","trackType":"spotify","codec":"ogg","seek":0,"duration":173,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":91,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Sep 07 23:29:18 volumio volumio[903]: info: Sending Spotify command to local API: /player/pause Sep 07 23:29:18 volumio volumio[903]: info: CorePlayQueue::clearPlayQueue Sep 07 23:29:18 volumio volumio[903]: info: CorePlayQueue::saveQueue Sep 07 23:29:18 volumio volumio[903]: info: CoreCommandRouter::volumioPushQueue Sep 07 23:29:18 volumio volumio[903]: info: CoreStateMachine::addQueueItems Sep 07 23:29:18 volumio volumio[903]: info: CorePlayQueue::addQueueItems Sep 07 23:29:18 volumio volumio[903]: info: Preload queue cleared Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:3m7jsBiMxam6FdxHUH5IWm Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:3m7jsBiMxam6FdxHUH5IWm Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:0Ckut00dWyBA4Gqdg3Cy6F Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:0Ckut00dWyBA4Gqdg3Cy6F Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:1iL5DwPJVa3b2TEJAHnreJ Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:1iL5DwPJVa3b2TEJAHnreJ Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:60EXXuME5NO8t8F0SkUvn1 Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:60EXXuME5NO8t8F0SkUvn1 Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:5Kflcwxjthdx4ABfr41ub8 Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:5Kflcwxjthdx4ABfr41ub8 Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:18OrnYJ4JJB5YODYP6bsly Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:18OrnYJ4JJB5YODYP6bsly Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:0TX3ylYLBKYBDv7RVcjwro Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:0TX3ylYLBKYBDv7RVcjwro Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:3QaHdolrs2FfCcnOe96jRB Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:3QaHdolrs2FfCcnOe96jRB Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:3x1W0QWwaTLgFjphimwCkM Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:3x1W0QWwaTLgFjphimwCkM Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:4g87drXuYFrWby45YCK1Ac Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:4g87drXuYFrWby45YCK1Ac Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:4ij0h1lRybCDRGBvEcAYwN Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:4ij0h1lRybCDRGBvEcAYwN Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:6nr526fDRzpwKFsl9UeKPe Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:6nr526fDRzpwKFsl9UeKPe Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:7a63wruWSmcvt4bHNXq8qi Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:7a63wruWSmcvt4bHNXq8qi Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:6cLqmPbErRgLZVY1Qf8pO1 Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:6cLqmPbErRgLZVY1Qf8pO1 Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:10GQFZd42RhcjEMKY6kDu6 Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:10GQFZd42RhcjEMKY6kDu6 Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:1T9L0k4ZxOhlRgx3SR8C42 Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:1T9L0k4ZxOhlRgx3SR8C42 Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:7FaSIlhdAVhM5GpoBut23A Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:7FaSIlhdAVhM5GpoBut23A Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:2wgd2LdI6VRXtLvJv4N34j Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:2wgd2LdI6VRXtLvJv4N34j Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:6ZqWnSvmi6u8f4FxEHyqH3 Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:6ZqWnSvmi6u8f4FxEHyqH3 Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:2rIObYzNjo15RqXKADsfCj Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:2rIObYzNjo15RqXKADsfCj Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:742xORxrc8mCcKkLTMY5W8 Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:742xORxrc8mCcKkLTMY5W8 Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:5wJO9xnIa0PTqKGfrz70H7 Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:5wJO9xnIa0PTqKGfrz70H7 Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:4LdgTEMnxlFbXqDNvnCqAW Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:4LdgTEMnxlFbXqDNvnCqAW Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:7ychhJCL8wdaDtUpMR6z3M Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:7ychhJCL8wdaDtUpMR6z3M Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:204z55ipM2WaXF2h4Ce8Ql Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:204z55ipM2WaXF2h4Ce8Ql Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:3imtlETzn51gH6v0AoDoud Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:3imtlETzn51gH6v0AoDoud Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:484WZZxRC7hBM5gDZOdQQy Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:484WZZxRC7hBM5gDZOdQQy Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:29cVdn9QH0CcfKLB2OuppS Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:29cVdn9QH0CcfKLB2OuppS Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:1rwhnruxWcovn37G6rWXyV Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:1rwhnruxWcovn37G6rWXyV Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:39z0Q92Hq4fL8gfeMLLzj5 Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:39z0Q92Hq4fL8gfeMLLzj5 Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:6x8SdF7t6LIXI0qXFd7Ge1 Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:6x8SdF7t6LIXI0qXFd7Ge1 Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:4D2Sh4IhWg5HPlRnI4iyzE Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:4D2Sh4IhWg5HPlRnI4iyzE Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:19dvP4cDJ0xtaZXUkNVJwi Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:19dvP4cDJ0xtaZXUkNVJwi Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:7ptnGvzu1WxowaLrf4sQZy Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:7ptnGvzu1WxowaLrf4sQZy Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:7lcQd1wBXSCIpOzI0oZb9h Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:7lcQd1wBXSCIpOzI0oZb9h Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:4zmaXq9a2gZ5l2ko0247xR Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:4zmaXq9a2gZ5l2ko0247xR Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:6Ys081wMm9uKoCMMZVU63S Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:6Ys081wMm9uKoCMMZVU63S Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:5Ekztt86kMO32saja9gT1j Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:5Ekztt86kMO32saja9gT1j Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:0yhaxHsepqgh6fgzYwedOu Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:0yhaxHsepqgh6fgzYwedOu Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:7nspwxKGUvwZQCu1Ctdu5m Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:7nspwxKGUvwZQCu1Ctdu5m Sep 07 23:29:18 volumio volumio[903]: info: Adding Item to queue: spotify:track:6PV0SXNxQlLFi6Y2CFMCkW Sep 07 23:29:18 volumio volumio[903]: info: Using cached record of: spotify:track:6PV0SXNxQlLFi6Y2CFMCkW Sep 07 23:29:18 volumio ntpd[2696]: Soliciting pool server 195.137.202.130 Sep 07 23:29:18 volumio ntpd[2696]: Soliciting pool server 91.236.251.14 Sep 07 23:29:18 volumio volumio[903]: info: CoreCommandRouter::volumioPushQueue Sep 07 23:29:18 volumio volumio[903]: info: CorePlayQueue::saveQueue Sep 07 23:29:18 volumio volumio[903]: info: CoreStateMachine::updateTrackBlock Sep 07 23:29:18 volumio volumio[903]: info: CorePlayQueue::getTrackBlock Sep 07 23:29:18 volumio volumio[903]: info: CoreCommandRouter::volumioPlay Sep 07 23:29:18 volumio volumio[903]: info: CoreStateMachine::play index 24 Sep 07 23:29:18 volumio volumio[903]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 23:29:18 volumio volumio[903]: info: CoreStateMachine::stop Sep 07 23:29:18 volumio volumio[903]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 23:29:18 volumio volumio[903]: info: CoreStateMachine::play index undefined Sep 07 23:29:18 volumio volumio[903]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 23:29:18 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:18 volumio volumio[903]: info: CoreStateMachine::startPlaybackTimer Sep 07 23:29:18 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:18 volumio volumio[903]: info: [1725740958658] ControllerSpotify::clearAddPlayTrack Sep 07 23:29:18 volumio volumio[903]: info: Sending Spotify command with payload to local API: /player/play Sep 07 23:29:18 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:18 volumio go-librespot[2366]: time="2024-09-07T23:29:18+03:00" level=debug msg="pause track at 8944ms" Sep 07 23:29:18 volumio go-librespot[2366]: time="2024-09-07T23:29:18+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:18 volumio go-librespot[2366]: time="2024-09-07T23:29:18+03:00" level=debug msg="resolved context of track" uri="spotify:track:204z55ipM2WaXF2h4Ce8Ql" Sep 07 23:29:18 volumio go-librespot[2366]: time="2024-09-07T23:29:18+03:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:204z55ipM2WaXF2h4Ce8Ql" Sep 07 23:29:18 volumio go-librespot[2366]: time="2024-09-07T23:29:18+03:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:204z55ipM2WaXF2h4Ce8Ql" Sep 07 23:29:18 volumio go-librespot[2366]: time="2024-09-07T23:29:18+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:18 volumio go-librespot[2366]: time="2024-09-07T23:29:18+03:00" level=trace msg="emitting websocket event: will_play" Sep 07 23:29:18 volumio volumio[903]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","play_origin":"go-librespot"}} Sep 07 23:29:19 volumio go-librespot[2366]: time="2024-09-07T23:29:19+03:00" level=debug msg="selected format OGG_VORBIS_320 (072f0839040387c0bbbfa8983d85568dc67e6235)" uri="spotify:track:204z55ipM2WaXF2h4Ce8Ql" Sep 07 23:29:19 volumio go-librespot[2366]: time="2024-09-07T23:29:19+03:00" level=debug msg="requested aes key for file 072f0839040387c0bbbfa8983d85568dc67e6235, gid: 204z55ipM2WaXF2h4Ce8Ql" Sep 07 23:29:19 volumio ntpd[2696]: Soliciting pool server 37.53.92.252 Sep 07 23:29:19 volumio ntpd[2696]: Soliciting pool server 213.231.5.55 Sep 07 23:29:19 volumio volumio[903]: info: CoreCommandRouter::volumioSeek Sep 07 23:29:19 volumio volumio[903]: info: CoreStateMachine::seek Sep 07 23:29:19 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:19 volumio volumio[903]: info: TRACKBLOCK {"uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","service":"spop","name":"What a Wonderful World","artist":"Graziatto","album":"Sax Covers, Vol. 1","type":"song","duration":142,"albumart":"https://i.scdn.co/image/ab67616d0000b27396e741604830a7ddfc642056","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"} Sep 07 23:29:19 volumio volumio[903]: info: CoreStateMachine::startPlaybackTimer Sep 07 23:29:19 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:19 volumio volumio[903]: info: Spotify seek to: 44000 Sep 07 23:29:19 volumio volumio[903]: info: Sending Spotify command with payload to local API: /player/seek Sep 07 23:29:19 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:19 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:19 volumio volumio[903]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 23:29:19 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:19 volumio ntpd[2696]: Soliciting pool server 193.106.144.13 Sep 07 23:29:19 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:19 volumio go-librespot[2366]: time="2024-09-07T23:29:19+03:00" level=debug msg="fetched first chunk of 9, total size is 4468816 bytes" uri="spotify:track:204z55ipM2WaXF2h4Ce8Ql" Sep 07 23:29:19 volumio go-librespot[2366]: time="2024-09-07T23:29:19+03:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:204z55ipM2WaXF2h4Ce8Ql" Sep 07 23:29:20 volumio go-librespot[2366]: time="2024-09-07T23:29:20+03:00" level=debug msg="fetched chunk 3/8, size: 524288" uri="spotify:track:204z55ipM2WaXF2h4Ce8Ql" Sep 07 23:29:20 volumio go-librespot[2366]: time="2024-09-07T23:29:20+03:00" level=debug msg="fetched chunk 1/8, size: 524288" uri="spotify:track:204z55ipM2WaXF2h4Ce8Ql" Sep 07 23:29:20 volumio go-librespot[2366]: time="2024-09-07T23:29:20+03:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5011 us, period size = 221 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 99 frames" Sep 07 23:29:20 volumio go-librespot[2366]: time="2024-09-07T23:29:20+03:00" level=info msg="loaded track \"What a Wonderful World\" (paused: false, position: 0ms, duration: 142680ms, prefetched: false)" uri="spotify:track:204z55ipM2WaXF2h4Ce8Ql" Sep 07 23:29:20 volumio go-librespot[2366]: time="2024-09-07T23:29:20+03:00" level=debug msg="fetched chunk 2/8, size: 524288" uri="spotify:track:204z55ipM2WaXF2h4Ce8Ql" Sep 07 23:29:20 volumio go-librespot[2366]: time="2024-09-07T23:29:20+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:20 volumio go-librespot[2366]: time="2024-09-07T23:29:20+03:00" level=trace msg="scheduling prefetch in 112s" Sep 07 23:29:20 volumio go-librespot[2366]: time="2024-09-07T23:29:20+03:00" level=trace msg="emitting websocket event: metadata" Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","name":"What a Wonderful World","artist_names":["Graziatto"],"album_name":"Sax Covers, Vol. 1","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0296e741604830a7ddfc642056","position":0,"duration":142680,"release_date":"year:2020 month:4 day:8","track_number":14,"disc_number":1}} Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","name":"What a Wonderful World","artist_names":["Graziatto"],"album_name":"Sax Covers, Vol. 1","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0296e741604830a7ddfc642056","position":0,"duration":142680,"release_date":"year:2020 month:4 day:8","track_number":14,"disc_number":1}} Sep 07 23:29:20 volumio go-librespot[2366]: time="2024-09-07T23:29:20+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:20 volumio go-librespot[2366]: time="2024-09-07T23:29:20+03:00" level=trace msg="emitting websocket event: paused" Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","play_origin":"go-librespot"}} Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: {"status":"pause","service":"spop","title":"What a Wonderful World","artist":"Graziatto","album":"Sax Covers, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d00001e0296e741604830a7ddfc642056","uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","trackType":"spotify","seek":0,"duration":142,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:20 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:20 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:20 volumio volumio[903]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"What a Wonderful World","artist":"Graziatto","album":"Sax Covers, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d00001e0296e741604830a7ddfc642056","uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","trackType":"spotify","seek":0,"duration":142,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:20 volumio volumio[903]: verbose: CURRENT POSITION 24 Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::syncState stateService pause Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus stop Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:20 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:20 volumio volumio[903]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 23:29:20 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","play_origin":"go-librespot"}} Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: {"status":"pause","service":"spop","title":"What a Wonderful World","artist":"Graziatto","album":"Sax Covers, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d00001e0296e741604830a7ddfc642056","uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","trackType":"spotify","seek":0,"duration":142,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:20 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:20 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:20 volumio volumio[903]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"What a Wonderful World","artist":"Graziatto","album":"Sax Covers, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d00001e0296e741604830a7ddfc642056","uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","trackType":"spotify","seek":0,"duration":142,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:20 volumio volumio[903]: verbose: CURRENT POSITION 24 Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::syncState stateService pause Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus stop Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:20 volumio go-librespot[2366]: time="2024-09-07T23:29:20+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:20 volumio go-librespot[2366]: time="2024-09-07T23:29:20+03:00" level=trace msg="emitting websocket event: playing" Sep 07 23:29:20 volumio go-librespot[2366]: time="2024-09-07T23:29:20+03:00" level=debug msg="seek track to 44000ms" Sep 07 23:29:20 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:20 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:20 volumio go-librespot[2366]: time="2024-09-07T23:29:20+03:00" level=trace msg="seek to 44000ms (diff: 134ms, samples: 1940400, bytes: 1361532)" uri="spotify:track:204z55ipM2WaXF2h4Ce8Ql" Sep 07 23:29:20 volumio ntpd[2696]: Soliciting pool server 193.106.144.7 Sep 07 23:29:20 volumio ntpd[2696]: Soliciting pool server 188.191.234.54 Sep 07 23:29:20 volumio ntpd[2696]: Soliciting pool server 91.236.251.29 Sep 07 23:29:20 volumio go-librespot[2366]: time="2024-09-07T23:29:20+03:00" level=debug msg="fetched chunk 4/8, size: 524288" uri="spotify:track:204z55ipM2WaXF2h4Ce8Ql" Sep 07 23:29:20 volumio go-librespot[2366]: time="2024-09-07T23:29:20+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:20 volumio go-librespot[2366]: time="2024-09-07T23:29:20+03:00" level=trace msg="scheduling prefetch in 69s" Sep 07 23:29:20 volumio go-librespot[2366]: time="2024-09-07T23:29:20+03:00" level=trace msg="emitting websocket event: seek" Sep 07 23:29:20 volumio ntpd[2696]: Soliciting pool server 162.159.200.1 Sep 07 23:29:20 volumio go-librespot[2366]: time="2024-09-07T23:29:20+03:00" level=debug msg="fetched chunk 5/8, size: 524288" uri="spotify:track:204z55ipM2WaXF2h4Ce8Ql" Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","play_origin":"go-librespot"}} Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: {"status":"play","service":"spop","title":"What a Wonderful World","artist":"Graziatto","album":"Sax Covers, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d00001e0296e741604830a7ddfc642056","uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","trackType":"spotify","seek":0,"duration":142,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:20 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:20 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:20 volumio volumio[903]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"What a Wonderful World","artist":"Graziatto","album":"Sax Covers, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d00001e0296e741604830a7ddfc642056","uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","trackType":"spotify","seek":0,"duration":142,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:20 volumio volumio[903]: verbose: CURRENT POSITION 24 Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::syncState stateService play Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus stop Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","position":44000,"duration":142680,"play_origin":"go-librespot"}} Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: {"status":"play","service":"spop","title":"What a Wonderful World","artist":"Graziatto","album":"Sax Covers, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d00001e0296e741604830a7ddfc642056","uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","trackType":"spotify","seek":44000,"duration":142,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:20 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:20 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:20 volumio volumio[903]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"What a Wonderful World","artist":"Graziatto","album":"Sax Covers, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d00001e0296e741604830a7ddfc642056","uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","trackType":"spotify","seek":44000,"duration":142,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:20 volumio volumio[903]: verbose: CURRENT POSITION 24 Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::syncState stateService play Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus play Sep 07 23:29:20 volumio volumio[903]: info: Received an update from plugin. extracting info from payload Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:20 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:20 volumio volumio[903]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 23:29:20 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:20 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:20 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","play_origin":"go-librespot"}} Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: {"status":"play","service":"spop","title":"What a Wonderful World","artist":"Graziatto","album":"Sax Covers, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d00001e0296e741604830a7ddfc642056","uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","trackType":"spotify","seek":44000,"duration":142,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:20 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:20 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:20 volumio volumio[903]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"What a Wonderful World","artist":"Graziatto","album":"Sax Covers, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d00001e0296e741604830a7ddfc642056","uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","trackType":"spotify","seek":44000,"duration":142,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:20 volumio volumio[903]: verbose: CURRENT POSITION 24 Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::syncState stateService play Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus play Sep 07 23:29:20 volumio volumio[903]: info: Received an update from plugin. extracting info from payload Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:20 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:20 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:20 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:20 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","position":44000,"duration":142680,"play_origin":"go-librespot"}} Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:20 volumio volumio[903]: SPOTIFY: {"status":"play","service":"spop","title":"What a Wonderful World","artist":"Graziatto","album":"Sax Covers, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d00001e0296e741604830a7ddfc642056","uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","trackType":"spotify","seek":44000,"duration":142,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:20 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:20 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:20 volumio volumio[903]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"What a Wonderful World","artist":"Graziatto","album":"Sax Covers, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d00001e0296e741604830a7ddfc642056","uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","trackType":"spotify","seek":44000,"duration":142,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:20 volumio volumio[903]: verbose: CURRENT POSITION 24 Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::syncState stateService play Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus play Sep 07 23:29:20 volumio volumio[903]: info: Received an update from plugin. extracting info from payload Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:20 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:20 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:20 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:20 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:20 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:21 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:21 volumio volumio[903]: SPOTIFY: {"status":"play","service":"spop","title":"What a Wonderful World","artist":"Graziatto","album":"Sax Covers, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d00001e0296e741604830a7ddfc642056","uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","trackType":"spotify","seek":44000,"duration":142,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:21 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:21 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:21 volumio volumio[903]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"What a Wonderful World","artist":"Graziatto","album":"Sax Covers, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d00001e0296e741604830a7ddfc642056","uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","trackType":"spotify","seek":44000,"duration":142,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:21 volumio volumio[903]: verbose: CURRENT POSITION 24 Sep 07 23:29:21 volumio volumio[903]: info: CoreStateMachine::syncState stateService play Sep 07 23:29:21 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus play Sep 07 23:29:21 volumio volumio[903]: info: Received an update from plugin. extracting info from payload Sep 07 23:29:21 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:21 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:21 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:21 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:21 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:21 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:21 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:21 volumio volumio[903]: SPOTIFY: {"status":"play","service":"spop","title":"What a Wonderful World","artist":"Graziatto","album":"Sax Covers, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d00001e0296e741604830a7ddfc642056","uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","trackType":"spotify","seek":44000,"duration":142,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:21 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:21 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:21 volumio volumio[903]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"What a Wonderful World","artist":"Graziatto","album":"Sax Covers, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d00001e0296e741604830a7ddfc642056","uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","trackType":"spotify","seek":44000,"duration":142,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:21 volumio volumio[903]: verbose: CURRENT POSITION 24 Sep 07 23:29:21 volumio volumio[903]: info: CoreStateMachine::syncState stateService play Sep 07 23:29:21 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus play Sep 07 23:29:21 volumio volumio[903]: info: Received an update from plugin. extracting info from payload Sep 07 23:29:21 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:21 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:21 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:21 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:21 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:21 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:21 volumio ntpd[2696]: Soliciting pool server 193.106.144.6 Sep 07 23:29:21 volumio ntpd[2696]: Soliciting pool server 91.236.251.24 Sep 07 23:29:21 volumio ntpd[2696]: Soliciting pool server 78.30.254.80 Sep 07 23:29:21 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:21 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:21 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:21 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:21 volumio ntpd[2696]: Soliciting pool server 194.54.80.29 Sep 07 23:29:21 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:21 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:21 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:21 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:21 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:22 volumio ntpd[2696]: Soliciting pool server 79.142.192.130 Sep 07 23:29:22 volumio ntpd[2696]: Soliciting pool server 193.34.155.3 Sep 07 23:29:22 volumio ntpd[2696]: Soliciting pool server 91.236.251.35 Sep 07 23:29:23 volumio ntpd[2696]: Soliciting pool server 37.53.87.250 Sep 07 23:29:23 volumio ntpd[2696]: Soliciting pool server 2606:4700:f1::1 Sep 07 23:29:23 volumio ntpd[2696]: Soliciting pool server 91.236.251.234 Sep 07 23:29:26 volumio go-librespot[2366]: time="2024-09-07T23:29:26+03:00" level=debug msg="fetched chunk 6/8, size: 524288" uri="spotify:track:204z55ipM2WaXF2h4Ce8Ql" Sep 07 23:29:27 volumio volumio[903]: info: Preload queue cleared Sep 07 23:29:27 volumio volumio[903]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 07 23:29:27 volumio volumio[903]: info: CoreStateMachine::ClearQueue Sep 07 23:29:27 volumio volumio[903]: info: CoreStateMachine::stop Sep 07 23:29:27 volumio volumio[903]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 23:29:27 volumio volumio[903]: info: CoreStateMachine::stPlaybackTimer Sep 07 23:29:27 volumio volumio[903]: info: CoreStateMachine::updateTrackBlock Sep 07 23:29:27 volumio volumio[903]: info: CorePlayQueue::getTrackBlock Sep 07 23:29:27 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:27 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:27 volumio volumio[903]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 23:29:27 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:27 volumio volumio[903]: info: CoreStateMachine::serviceStop Sep 07 23:29:27 volumio volumio[903]: info: CorePlayQueue::getTrack 24 Sep 07 23:29:27 volumio volumio[903]: info: CoreCommandRouter::serviceStop Sep 07 23:29:27 volumio volumio[903]: info: Spotify Stop Sep 07 23:29:27 volumio volumio[903]: SPOTIFY: SPOTIFY STOP Sep 07 23:29:27 volumio volumio[903]: SPOTIFY: {"status":"play","position":24,"title":"What a Wonderful World","artist":"Graziatto","album":"Sax Covers, Vol. 1","albumart":"https://i.scdn.co/image/ab67616d0000b27396e741604830a7ddfc642056","uri":"spotify:track:204z55ipM2WaXF2h4Ce8Ql","trackType":"spotify","codec":"ogg","seek":44000,"duration":142,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":91,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Sep 07 23:29:27 volumio volumio[903]: info: Sending Spotify command to local API: /player/pause Sep 07 23:29:27 volumio volumio[903]: info: CorePlayQueue::clearPlayQueue Sep 07 23:29:27 volumio volumio[903]: info: CorePlayQueue::saveQueue Sep 07 23:29:27 volumio volumio[903]: info: CoreCommandRouter::volumioPushQueue Sep 07 23:29:27 volumio volumio[903]: info: CoreStateMachine::addQueueItems Sep 07 23:29:27 volumio volumio[903]: info: CorePlayQueue::addQueueItems Sep 07 23:29:27 volumio volumio[903]: info: Preload queue cleared Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:3m7jsBiMxam6FdxHUH5IWm Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:3m7jsBiMxam6FdxHUH5IWm Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:0Ckut00dWyBA4Gqdg3Cy6F Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:0Ckut00dWyBA4Gqdg3Cy6F Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:1iL5DwPJVa3b2TEJAHnreJ Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:1iL5DwPJVa3b2TEJAHnreJ Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:60EXXuME5NO8t8F0SkUvn1 Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:60EXXuME5NO8t8F0SkUvn1 Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:5Kflcwxjthdx4ABfr41ub8 Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:5Kflcwxjthdx4ABfr41ub8 Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:18OrnYJ4JJB5YODYP6bsly Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:18OrnYJ4JJB5YODYP6bsly Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:0TX3ylYLBKYBDv7RVcjwro Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:0TX3ylYLBKYBDv7RVcjwro Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:3QaHdolrs2FfCcnOe96jRB Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:3QaHdolrs2FfCcnOe96jRB Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:3x1W0QWwaTLgFjphimwCkM Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:3x1W0QWwaTLgFjphimwCkM Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:4g87drXuYFrWby45YCK1Ac Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:4g87drXuYFrWby45YCK1Ac Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:4ij0h1lRybCDRGBvEcAYwN Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:4ij0h1lRybCDRGBvEcAYwN Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:6nr526fDRzpwKFsl9UeKPe Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:6nr526fDRzpwKFsl9UeKPe Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:7a63wruWSmcvt4bHNXq8qi Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:7a63wruWSmcvt4bHNXq8qi Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:6cLqmPbErRgLZVY1Qf8pO1 Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:6cLqmPbErRgLZVY1Qf8pO1 Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:10GQFZd42RhcjEMKY6kDu6 Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:10GQFZd42RhcjEMKY6kDu6 Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:1T9L0k4ZxOhlRgx3SR8C42 Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:1T9L0k4ZxOhlRgx3SR8C42 Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:7FaSIlhdAVhM5GpoBut23A Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:7FaSIlhdAVhM5GpoBut23A Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:2wgd2LdI6VRXtLvJv4N34j Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:2wgd2LdI6VRXtLvJv4N34j Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:6ZqWnSvmi6u8f4FxEHyqH3 Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:6ZqWnSvmi6u8f4FxEHyqH3 Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:2rIObYzNjo15RqXKADsfCj Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:2rIObYzNjo15RqXKADsfCj Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:742xORxrc8mCcKkLTMY5W8 Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:742xORxrc8mCcKkLTMY5W8 Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:5wJO9xnIa0PTqKGfrz70H7 Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:5wJO9xnIa0PTqKGfrz70H7 Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:4LdgTEMnxlFbXqDNvnCqAW Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:4LdgTEMnxlFbXqDNvnCqAW Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:7ychhJCL8wdaDtUpMR6z3M Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:7ychhJCL8wdaDtUpMR6z3M Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:204z55ipM2WaXF2h4Ce8Ql Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:204z55ipM2WaXF2h4Ce8Ql Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:3imtlETzn51gH6v0AoDoud Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:3imtlETzn51gH6v0AoDoud Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:484WZZxRC7hBM5gDZOdQQy Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:484WZZxRC7hBM5gDZOdQQy Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:29cVdn9QH0CcfKLB2OuppS Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:29cVdn9QH0CcfKLB2OuppS Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:1rwhnruxWcovn37G6rWXyV Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:1rwhnruxWcovn37G6rWXyV Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:39z0Q92Hq4fL8gfeMLLzj5 Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:39z0Q92Hq4fL8gfeMLLzj5 Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:6x8SdF7t6LIXI0qXFd7Ge1 Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:6x8SdF7t6LIXI0qXFd7Ge1 Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:4D2Sh4IhWg5HPlRnI4iyzE Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:4D2Sh4IhWg5HPlRnI4iyzE Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:19dvP4cDJ0xtaZXUkNVJwi Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:19dvP4cDJ0xtaZXUkNVJwi Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:7ptnGvzu1WxowaLrf4sQZy Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:7ptnGvzu1WxowaLrf4sQZy Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:7lcQd1wBXSCIpOzI0oZb9h Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:7lcQd1wBXSCIpOzI0oZb9h Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:4zmaXq9a2gZ5l2ko0247xR Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:4zmaXq9a2gZ5l2ko0247xR Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:6Ys081wMm9uKoCMMZVU63S Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:6Ys081wMm9uKoCMMZVU63S Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:5Ekztt86kMO32saja9gT1j Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:5Ekztt86kMO32saja9gT1j Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:0yhaxHsepqgh6fgzYwedOu Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:0yhaxHsepqgh6fgzYwedOu Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:7nspwxKGUvwZQCu1Ctdu5m Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:7nspwxKGUvwZQCu1Ctdu5m Sep 07 23:29:27 volumio volumio[903]: info: Adding Item to queue: spotify:track:6PV0SXNxQlLFi6Y2CFMCkW Sep 07 23:29:27 volumio volumio[903]: info: Using cached record of: spotify:track:6PV0SXNxQlLFi6Y2CFMCkW Sep 07 23:29:27 volumio volumio[903]: info: CoreCommandRouter::volumioPushQueue Sep 07 23:29:27 volumio volumio[903]: info: CorePlayQueue::saveQueue Sep 07 23:29:27 volumio volumio[903]: info: CoreStateMachine::updateTrackBlock Sep 07 23:29:27 volumio volumio[903]: info: CorePlayQueue::getTrackBlock Sep 07 23:29:27 volumio volumio[903]: info: CoreCommandRouter::volumioPlay Sep 07 23:29:27 volumio volumio[903]: info: CoreStateMachine::play index 18 Sep 07 23:29:27 volumio volumio[903]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 23:29:27 volumio volumio[903]: info: CoreStateMachine::stop Sep 07 23:29:27 volumio volumio[903]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 23:29:27 volumio volumio[903]: info: CoreStateMachine::play index undefined Sep 07 23:29:27 volumio volumio[903]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 23:29:27 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:27 volumio volumio[903]: info: CoreStateMachine::startPlaybackTimer Sep 07 23:29:27 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:27 volumio volumio[903]: info: [1725740967396] ControllerSpotify::clearAddPlayTrack Sep 07 23:29:27 volumio volumio[903]: info: Sending Spotify command with payload to local API: /player/play Sep 07 23:29:27 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:27 volumio go-librespot[2366]: time="2024-09-07T23:29:27+03:00" level=debug msg="resolved context of track" uri="spotify:track:6ZqWnSvmi6u8f4FxEHyqH3" Sep 07 23:29:27 volumio go-librespot[2366]: time="2024-09-07T23:29:27+03:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:6ZqWnSvmi6u8f4FxEHyqH3" Sep 07 23:29:27 volumio go-librespot[2366]: time="2024-09-07T23:29:27+03:00" level=debug msg="loading track (paused: false, position: 2ms)" uri="spotify:track:6ZqWnSvmi6u8f4FxEHyqH3" Sep 07 23:29:27 volumio go-librespot[2366]: time="2024-09-07T23:29:27+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:27 volumio go-librespot[2366]: time="2024-09-07T23:29:27+03:00" level=trace msg="emitting websocket event: will_play" Sep 07 23:29:27 volumio volumio[903]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","play_origin":"go-librespot"}} Sep 07 23:29:27 volumio go-librespot[2366]: time="2024-09-07T23:29:27+03:00" level=debug msg="selected format OGG_VORBIS_320 (8ac0a660cd8c85190efa66185e9081801f6fa64d)" uri="spotify:track:6ZqWnSvmi6u8f4FxEHyqH3" Sep 07 23:29:27 volumio go-librespot[2366]: time="2024-09-07T23:29:27+03:00" level=debug msg="requested aes key for file 8ac0a660cd8c85190efa66185e9081801f6fa64d, gid: 6ZqWnSvmi6u8f4FxEHyqH3" Sep 07 23:29:28 volumio go-librespot[2366]: time="2024-09-07T23:29:28+03:00" level=debug msg="fetched first chunk of 19, total size is 9643904 bytes" uri="spotify:track:6ZqWnSvmi6u8f4FxEHyqH3" Sep 07 23:29:28 volumio go-librespot[2366]: time="2024-09-07T23:29:28+03:00" level=trace msg="seek to 2ms (diff: 2ms, samples: 88, bytes: 0)" uri="spotify:track:6ZqWnSvmi6u8f4FxEHyqH3" Sep 07 23:29:28 volumio go-librespot[2366]: time="2024-09-07T23:29:28+03:00" level=info msg="loaded track \"How deep is your love\" (paused: false, position: 2ms, duration: 256626ms, prefetched: false)" uri="spotify:track:6ZqWnSvmi6u8f4FxEHyqH3" Sep 07 23:29:28 volumio go-librespot[2366]: time="2024-09-07T23:29:28+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:28 volumio go-librespot[2366]: time="2024-09-07T23:29:28+03:00" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:6ZqWnSvmi6u8f4FxEHyqH3" Sep 07 23:29:28 volumio go-librespot[2366]: time="2024-09-07T23:29:28+03:00" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:6ZqWnSvmi6u8f4FxEHyqH3" Sep 07 23:29:28 volumio go-librespot[2366]: time="2024-09-07T23:29:28+03:00" level=trace msg="scheduling prefetch in 226s" Sep 07 23:29:28 volumio go-librespot[2366]: time="2024-09-07T23:29:28+03:00" level=trace msg="emitting websocket event: metadata" Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","name":"How deep is your love","artist_names":["SAMU SAX"],"album_name":"Nostalgias del sax","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02c9c78565a4f661fd085d628b","position":2,"duration":256626,"release_date":"year:2018 month:3 day:28","track_number":7,"disc_number":1}} Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","name":"How deep is your love","artist_names":["SAMU SAX"],"album_name":"Nostalgias del sax","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02c9c78565a4f661fd085d628b","position":2,"duration":256626,"release_date":"year:2018 month:3 day:28","track_number":7,"disc_number":1}} Sep 07 23:29:28 volumio go-librespot[2366]: time="2024-09-07T23:29:28+03:00" level=debug msg="pause track at 208ms" Sep 07 23:29:28 volumio go-librespot[2366]: time="2024-09-07T23:29:28+03:00" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:6ZqWnSvmi6u8f4FxEHyqH3" Sep 07 23:29:28 volumio go-librespot[2366]: time="2024-09-07T23:29:28+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:28 volumio go-librespot[2366]: time="2024-09-07T23:29:28+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:28 volumio go-librespot[2366]: time="2024-09-07T23:29:28+03:00" level=trace msg="emitting websocket event: playing" Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","play_origin":"go-librespot"}} Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: {"status":"play","service":"spop","title":"How deep is your love","artist":"SAMU SAX","album":"Nostalgias del sax","albumart":"https://i.scdn.co/image/ab67616d00001e02c9c78565a4f661fd085d628b","uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","trackType":"spotify","seek":2,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:28 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:28 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:28 volumio volumio[903]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"How deep is your love","artist":"SAMU SAX","album":"Nostalgias del sax","albumart":"https://i.scdn.co/image/ab67616d00001e02c9c78565a4f661fd085d628b","uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","trackType":"spotify","seek":2,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:28 volumio volumio[903]: verbose: CURRENT POSITION 18 Sep 07 23:29:28 volumio volumio[903]: info: CoreStateMachine::syncState stateService play Sep 07 23:29:28 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus stop Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","play_origin":"go-librespot"}} Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: {"status":"play","service":"spop","title":"How deep is your love","artist":"SAMU SAX","album":"Nostalgias del sax","albumart":"https://i.scdn.co/image/ab67616d00001e02c9c78565a4f661fd085d628b","uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","trackType":"spotify","seek":2,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:28 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:28 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:28 volumio volumio[903]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"How deep is your love","artist":"SAMU SAX","album":"Nostalgias del sax","albumart":"https://i.scdn.co/image/ab67616d00001e02c9c78565a4f661fd085d628b","uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","trackType":"spotify","seek":2,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:28 volumio volumio[903]: verbose: CURRENT POSITION 18 Sep 07 23:29:28 volumio volumio[903]: info: CoreStateMachine::syncState stateService play Sep 07 23:29:28 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus play Sep 07 23:29:28 volumio volumio[903]: info: Received an update from plugin. extracting info from payload Sep 07 23:29:28 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:28 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:28 volumio volumio[903]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 23:29:28 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:28 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:28 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:28 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:28 volumio go-librespot[2366]: time="2024-09-07T23:29:28+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:28 volumio go-librespot[2366]: time="2024-09-07T23:29:28+03:00" level=trace msg="emitting websocket event: paused" Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","play_origin":"go-librespot"}} Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: {"status":"pause","service":"spop","title":"How deep is your love","artist":"SAMU SAX","album":"Nostalgias del sax","albumart":"https://i.scdn.co/image/ab67616d00001e02c9c78565a4f661fd085d628b","uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","trackType":"spotify","seek":2,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:28 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:28 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:28 volumio volumio[903]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"How deep is your love","artist":"SAMU SAX","album":"Nostalgias del sax","albumart":"https://i.scdn.co/image/ab67616d00001e02c9c78565a4f661fd085d628b","uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","trackType":"spotify","seek":2,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:28 volumio volumio[903]: verbose: CURRENT POSITION 18 Sep 07 23:29:28 volumio volumio[903]: info: CoreStateMachine::syncState stateService pause Sep 07 23:29:28 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus play Sep 07 23:29:28 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:28 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:28 volumio volumio[903]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 23:29:28 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","play_origin":"go-librespot"}} Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: {"status":"pause","service":"spop","title":"How deep is your love","artist":"SAMU SAX","album":"Nostalgias del sax","albumart":"https://i.scdn.co/image/ab67616d00001e02c9c78565a4f661fd085d628b","uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","trackType":"spotify","seek":2,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:28 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:28 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:28 volumio volumio[903]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"How deep is your love","artist":"SAMU SAX","album":"Nostalgias del sax","albumart":"https://i.scdn.co/image/ab67616d00001e02c9c78565a4f661fd085d628b","uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","trackType":"spotify","seek":2,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:28 volumio volumio[903]: verbose: CURRENT POSITION 18 Sep 07 23:29:28 volumio volumio[903]: info: CoreStateMachine::syncState stateService pause Sep 07 23:29:28 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus play Sep 07 23:29:28 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:28 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:28 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:28 volumio volumio[903]: SPOTIFY: {"status":"pause","service":"spop","title":"How deep is your love","artist":"SAMU SAX","album":"Nostalgias del sax","albumart":"https://i.scdn.co/image/ab67616d00001e02c9c78565a4f661fd085d628b","uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","trackType":"spotify","seek":2,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:28 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:28 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:28 volumio volumio[903]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"How deep is your love","artist":"SAMU SAX","album":"Nostalgias del sax","albumart":"https://i.scdn.co/image/ab67616d00001e02c9c78565a4f661fd085d628b","uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","trackType":"spotify","seek":2,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:28 volumio volumio[903]: verbose: CURRENT POSITION 18 Sep 07 23:29:28 volumio volumio[903]: info: CoreStateMachine::syncState stateService pause Sep 07 23:29:28 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus play Sep 07 23:29:28 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:28 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:28 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:29 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:29 volumio volumio[903]: SPOTIFY: {"status":"pause","service":"spop","title":"How deep is your love","artist":"SAMU SAX","album":"Nostalgias del sax","albumart":"https://i.scdn.co/image/ab67616d00001e02c9c78565a4f661fd085d628b","uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","trackType":"spotify","seek":2,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:29 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:29 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:29 volumio volumio[903]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"How deep is your love","artist":"SAMU SAX","album":"Nostalgias del sax","albumart":"https://i.scdn.co/image/ab67616d00001e02c9c78565a4f661fd085d628b","uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","trackType":"spotify","seek":2,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:29 volumio volumio[903]: verbose: CURRENT POSITION 18 Sep 07 23:29:29 volumio volumio[903]: info: CoreStateMachine::syncState stateService pause Sep 07 23:29:29 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus play Sep 07 23:29:29 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:29 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:29 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:29 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:29 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:41 volumio volumio[903]: info: CoreCommandRouter::volumioSeek Sep 07 23:29:41 volumio volumio[903]: info: CoreStateMachine::seek Sep 07 23:29:41 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:41 volumio volumio[903]: info: TRACKBLOCK {"uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","service":"spop","name":"How deep is your love","artist":"SAMU SAX","album":"Nostalgias del sax","type":"song","duration":256,"albumart":"https://i.scdn.co/image/ab67616d0000b273c9c78565a4f661fd085d628b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify","channels":2} Sep 07 23:29:41 volumio volumio[903]: info: CoreStateMachine::startPlaybackTimer Sep 07 23:29:41 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:41 volumio volumio[903]: info: Spotify seek to: 98000 Sep 07 23:29:41 volumio volumio[903]: info: Sending Spotify command with payload to local API: /player/seek Sep 07 23:29:41 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:41 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:41 volumio volumio[903]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 23:29:41 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:41 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:41 volumio go-librespot[2366]: time="2024-09-07T23:29:41+03:00" level=debug msg="seek track to 98000ms" Sep 07 23:29:41 volumio go-librespot[2366]: time="2024-09-07T23:29:41+03:00" level=debug msg="fetched chunk 6/18, size: 524288" uri="spotify:track:6ZqWnSvmi6u8f4FxEHyqH3" Sep 07 23:29:41 volumio go-librespot[2366]: time="2024-09-07T23:29:41+03:00" level=trace msg="seek to 98000ms (diff: 101ms, samples: 4321800, bytes: 3583565)" uri="spotify:track:6ZqWnSvmi6u8f4FxEHyqH3" Sep 07 23:29:41 volumio go-librespot[2366]: time="2024-09-07T23:29:41+03:00" level=debug msg="fetched chunk 8/18, size: 524288" uri="spotify:track:6ZqWnSvmi6u8f4FxEHyqH3" Sep 07 23:29:41 volumio go-librespot[2366]: time="2024-09-07T23:29:41+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:41 volumio go-librespot[2366]: time="2024-09-07T23:29:41+03:00" level=trace msg="emitting websocket event: seek" Sep 07 23:29:41 volumio volumio[903]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","position":98000,"duration":256626,"play_origin":"go-librespot"}} Sep 07 23:29:41 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:41 volumio volumio[903]: SPOTIFY: {"status":"pause","service":"spop","title":"How deep is your love","artist":"SAMU SAX","album":"Nostalgias del sax","albumart":"https://i.scdn.co/image/ab67616d00001e02c9c78565a4f661fd085d628b","uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","trackType":"spotify","seek":98000,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:41 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:41 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:41 volumio volumio[903]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"How deep is your love","artist":"SAMU SAX","album":"Nostalgias del sax","albumart":"https://i.scdn.co/image/ab67616d00001e02c9c78565a4f661fd085d628b","uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","trackType":"spotify","seek":98000,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:41 volumio volumio[903]: verbose: CURRENT POSITION 18 Sep 07 23:29:41 volumio volumio[903]: info: CoreStateMachine::syncState stateService pause Sep 07 23:29:41 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus play Sep 07 23:29:41 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:41 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:41 volumio volumio[903]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 23:29:41 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:41 volumio go-librespot[2366]: time="2024-09-07T23:29:41+03:00" level=debug msg="fetched chunk 7/18, size: 524288" uri="spotify:track:6ZqWnSvmi6u8f4FxEHyqH3" Sep 07 23:29:41 volumio go-librespot[2366]: time="2024-09-07T23:29:41+03:00" level=debug msg="fetched chunk 9/18, size: 524288" uri="spotify:track:6ZqWnSvmi6u8f4FxEHyqH3" Sep 07 23:29:41 volumio volumio[903]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","position":98000,"duration":256626,"play_origin":"go-librespot"}} Sep 07 23:29:41 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:41 volumio volumio[903]: SPOTIFY: {"status":"pause","service":"spop","title":"How deep is your love","artist":"SAMU SAX","album":"Nostalgias del sax","albumart":"https://i.scdn.co/image/ab67616d00001e02c9c78565a4f661fd085d628b","uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","trackType":"spotify","seek":98000,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:41 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:41 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:41 volumio volumio[903]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"How deep is your love","artist":"SAMU SAX","album":"Nostalgias del sax","albumart":"https://i.scdn.co/image/ab67616d00001e02c9c78565a4f661fd085d628b","uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","trackType":"spotify","seek":98000,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:41 volumio volumio[903]: verbose: CURRENT POSITION 18 Sep 07 23:29:41 volumio volumio[903]: info: CoreStateMachine::syncState stateService pause Sep 07 23:29:41 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus play Sep 07 23:29:41 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:41 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:41 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:42 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:42 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:46 volumio volumio[903]: info: Preload queue cleared Sep 07 23:29:46 volumio volumio[903]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 07 23:29:46 volumio volumio[903]: info: CoreStateMachine::ClearQueue Sep 07 23:29:46 volumio volumio[903]: info: CoreStateMachine::stop Sep 07 23:29:46 volumio volumio[903]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 23:29:46 volumio volumio[903]: info: CoreStateMachine::stPlaybackTimer Sep 07 23:29:46 volumio volumio[903]: info: CoreStateMachine::updateTrackBlock Sep 07 23:29:46 volumio volumio[903]: info: CorePlayQueue::getTrackBlock Sep 07 23:29:46 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:46 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:46 volumio volumio[903]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 23:29:46 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:46 volumio volumio[903]: info: CoreStateMachine::serviceStop Sep 07 23:29:46 volumio volumio[903]: info: CorePlayQueue::getTrack 18 Sep 07 23:29:46 volumio volumio[903]: info: CoreCommandRouter::serviceStop Sep 07 23:29:46 volumio volumio[903]: info: Spotify Stop Sep 07 23:29:46 volumio volumio[903]: SPOTIFY: SPOTIFY STOP Sep 07 23:29:46 volumio volumio[903]: SPOTIFY: {"status":"play","position":18,"title":"How deep is your love","artist":"SAMU SAX","album":"Nostalgias del sax","albumart":"https://i.scdn.co/image/ab67616d0000b273c9c78565a4f661fd085d628b","uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","trackType":"spotify","codec":"ogg","seek":98251,"duration":256,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":91,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Sep 07 23:29:46 volumio volumio[903]: info: Sending Spotify command to local API: /player/pause Sep 07 23:29:46 volumio volumio[903]: info: CorePlayQueue::clearPlayQueue Sep 07 23:29:46 volumio volumio[903]: info: CorePlayQueue::saveQueue Sep 07 23:29:46 volumio volumio[903]: info: CoreCommandRouter::volumioPushQueue Sep 07 23:29:46 volumio volumio[903]: info: CoreStateMachine::addQueueItems Sep 07 23:29:46 volumio volumio[903]: info: CorePlayQueue::addQueueItems Sep 07 23:29:46 volumio volumio[903]: info: Preload queue cleared Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:3m7jsBiMxam6FdxHUH5IWm Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:3m7jsBiMxam6FdxHUH5IWm Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:0Ckut00dWyBA4Gqdg3Cy6F Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:0Ckut00dWyBA4Gqdg3Cy6F Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:1iL5DwPJVa3b2TEJAHnreJ Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:1iL5DwPJVa3b2TEJAHnreJ Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:60EXXuME5NO8t8F0SkUvn1 Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:60EXXuME5NO8t8F0SkUvn1 Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:5Kflcwxjthdx4ABfr41ub8 Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:5Kflcwxjthdx4ABfr41ub8 Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:18OrnYJ4JJB5YODYP6bsly Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:18OrnYJ4JJB5YODYP6bsly Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:0TX3ylYLBKYBDv7RVcjwro Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:0TX3ylYLBKYBDv7RVcjwro Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:3QaHdolrs2FfCcnOe96jRB Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:3QaHdolrs2FfCcnOe96jRB Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:3x1W0QWwaTLgFjphimwCkM Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:3x1W0QWwaTLgFjphimwCkM Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:4g87drXuYFrWby45YCK1Ac Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:4g87drXuYFrWby45YCK1Ac Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:4ij0h1lRybCDRGBvEcAYwN Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:4ij0h1lRybCDRGBvEcAYwN Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:6nr526fDRzpwKFsl9UeKPe Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:6nr526fDRzpwKFsl9UeKPe Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:7a63wruWSmcvt4bHNXq8qi Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:7a63wruWSmcvt4bHNXq8qi Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:6cLqmPbErRgLZVY1Qf8pO1 Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:6cLqmPbErRgLZVY1Qf8pO1 Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:10GQFZd42RhcjEMKY6kDu6 Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:10GQFZd42RhcjEMKY6kDu6 Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:1T9L0k4ZxOhlRgx3SR8C42 Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:1T9L0k4ZxOhlRgx3SR8C42 Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:7FaSIlhdAVhM5GpoBut23A Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:7FaSIlhdAVhM5GpoBut23A Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:2wgd2LdI6VRXtLvJv4N34j Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:2wgd2LdI6VRXtLvJv4N34j Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:6ZqWnSvmi6u8f4FxEHyqH3 Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:6ZqWnSvmi6u8f4FxEHyqH3 Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:2rIObYzNjo15RqXKADsfCj Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:2rIObYzNjo15RqXKADsfCj Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:742xORxrc8mCcKkLTMY5W8 Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:742xORxrc8mCcKkLTMY5W8 Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:5wJO9xnIa0PTqKGfrz70H7 Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:5wJO9xnIa0PTqKGfrz70H7 Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:4LdgTEMnxlFbXqDNvnCqAW Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:4LdgTEMnxlFbXqDNvnCqAW Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:7ychhJCL8wdaDtUpMR6z3M Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:7ychhJCL8wdaDtUpMR6z3M Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:204z55ipM2WaXF2h4Ce8Ql Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:204z55ipM2WaXF2h4Ce8Ql Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:3imtlETzn51gH6v0AoDoud Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:3imtlETzn51gH6v0AoDoud Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:484WZZxRC7hBM5gDZOdQQy Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:484WZZxRC7hBM5gDZOdQQy Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:29cVdn9QH0CcfKLB2OuppS Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:29cVdn9QH0CcfKLB2OuppS Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:1rwhnruxWcovn37G6rWXyV Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:1rwhnruxWcovn37G6rWXyV Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:39z0Q92Hq4fL8gfeMLLzj5 Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:39z0Q92Hq4fL8gfeMLLzj5 Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:6x8SdF7t6LIXI0qXFd7Ge1 Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:6x8SdF7t6LIXI0qXFd7Ge1 Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:4D2Sh4IhWg5HPlRnI4iyzE Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:4D2Sh4IhWg5HPlRnI4iyzE Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:19dvP4cDJ0xtaZXUkNVJwi Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:19dvP4cDJ0xtaZXUkNVJwi Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:7ptnGvzu1WxowaLrf4sQZy Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:7ptnGvzu1WxowaLrf4sQZy Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:7lcQd1wBXSCIpOzI0oZb9h Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:7lcQd1wBXSCIpOzI0oZb9h Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:4zmaXq9a2gZ5l2ko0247xR Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:4zmaXq9a2gZ5l2ko0247xR Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:6Ys081wMm9uKoCMMZVU63S Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:6Ys081wMm9uKoCMMZVU63S Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:5Ekztt86kMO32saja9gT1j Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:5Ekztt86kMO32saja9gT1j Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:0yhaxHsepqgh6fgzYwedOu Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:0yhaxHsepqgh6fgzYwedOu Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:7nspwxKGUvwZQCu1Ctdu5m Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:7nspwxKGUvwZQCu1Ctdu5m Sep 07 23:29:46 volumio volumio[903]: info: Adding Item to queue: spotify:track:6PV0SXNxQlLFi6Y2CFMCkW Sep 07 23:29:46 volumio volumio[903]: info: Using cached record of: spotify:track:6PV0SXNxQlLFi6Y2CFMCkW Sep 07 23:29:46 volumio volumio[903]: info: CoreCommandRouter::volumioPushQueue Sep 07 23:29:46 volumio volumio[903]: info: CorePlayQueue::saveQueue Sep 07 23:29:47 volumio volumio[903]: info: CoreStateMachine::updateTrackBlock Sep 07 23:29:47 volumio volumio[903]: info: CorePlayQueue::getTrackBlock Sep 07 23:29:47 volumio volumio[903]: info: CoreCommandRouter::volumioPlay Sep 07 23:29:47 volumio volumio[903]: info: CoreStateMachine::play index 26 Sep 07 23:29:47 volumio volumio[903]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 23:29:47 volumio volumio[903]: info: CoreStateMachine::stop Sep 07 23:29:47 volumio volumio[903]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 23:29:47 volumio volumio[903]: info: CoreStateMachine::play index undefined Sep 07 23:29:47 volumio volumio[903]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 23:29:47 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:29:47 volumio volumio[903]: info: CoreStateMachine::startPlaybackTimer Sep 07 23:29:47 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:29:47 volumio volumio[903]: info: [1725740987027] ControllerSpotify::clearAddPlayTrack Sep 07 23:29:47 volumio volumio[903]: info: Sending Spotify command with payload to local API: /player/play Sep 07 23:29:47 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:47 volumio go-librespot[2366]: time="2024-09-07T23:29:47+03:00" level=debug msg="pause track at 97899ms" Sep 07 23:29:47 volumio go-librespot[2366]: time="2024-09-07T23:29:47+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:47 volumio go-librespot[2366]: time="2024-09-07T23:29:47+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:47 volumio go-librespot[2366]: time="2024-09-07T23:29:47+03:00" level=trace msg="emitting websocket event: paused" Sep 07 23:29:47 volumio volumio[903]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","play_origin":"go-librespot"}} Sep 07 23:29:47 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:47 volumio volumio[903]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:47 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:47 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:29:47 volumio volumio[903]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:47 volumio volumio[903]: verbose: CURRENT POSITION 26 Sep 07 23:29:47 volumio volumio[903]: info: CoreStateMachine::syncState stateService pause Sep 07 23:29:47 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus stop Sep 07 23:29:47 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:47 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:29:47 volumio volumio[903]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 23:29:47 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:47 volumio go-librespot[2366]: time="2024-09-07T23:29:47+03:00" level=debug msg="resolved context of track" uri="spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm" Sep 07 23:29:47 volumio go-librespot[2366]: time="2024-09-07T23:29:47+03:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm" Sep 07 23:29:47 volumio go-librespot[2366]: time="2024-09-07T23:29:47+03:00" level=debug msg="loading track (paused: false, position: 2ms)" uri="spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm" Sep 07 23:29:47 volumio volumio[903]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:6ZqWnSvmi6u8f4FxEHyqH3","play_origin":"go-librespot"}} Sep 07 23:29:47 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:47 volumio volumio[903]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:47 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:47 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:29:47 volumio volumio[903]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:47 volumio volumio[903]: verbose: CURRENT POSITION 26 Sep 07 23:29:47 volumio volumio[903]: info: CoreStateMachine::syncState stateService pause Sep 07 23:29:47 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus stop Sep 07 23:29:47 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:47 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:29:47 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:47 volumio go-librespot[2366]: time="2024-09-07T23:29:47+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:47 volumio go-librespot[2366]: time="2024-09-07T23:29:47+03:00" level=trace msg="emitting websocket event: will_play" Sep 07 23:29:47 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:47 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:47 volumio volumio[903]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","play_origin":"go-librespot"}} Sep 07 23:29:47 volumio volumio[903]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","play_origin":"go-librespot"}} Sep 07 23:29:47 volumio go-librespot[2366]: time="2024-09-07T23:29:47+03:00" level=debug msg="selected format OGG_VORBIS_320 (46e857d19f09bf261ef6728e07e2443ca406061a)" uri="spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm" Sep 07 23:29:47 volumio go-librespot[2366]: time="2024-09-07T23:29:47+03:00" level=debug msg="requested aes key for file 46e857d19f09bf261ef6728e07e2443ca406061a, gid: 77bnQRhEsVQ8ZPJ7jzEIdm" Sep 07 23:29:47 volumio go-librespot[2366]: time="2024-09-07T23:29:47+03:00" level=debug msg="fetched first chunk of 25, total size is 12781164 bytes" uri="spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm" Sep 07 23:29:47 volumio go-librespot[2366]: time="2024-09-07T23:29:47+03:00" level=trace msg="seek to 2ms (diff: 2ms, samples: 88, bytes: 0)" uri="spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm" Sep 07 23:29:47 volumio go-librespot[2366]: time="2024-09-07T23:29:47+03:00" level=debug msg="fetched chunk 1/24, size: 524288" uri="spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm" Sep 07 23:29:47 volumio go-librespot[2366]: time="2024-09-07T23:29:47+03:00" level=debug msg="fetched chunk 2/24, size: 524288" uri="spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm" Sep 07 23:29:47 volumio go-librespot[2366]: time="2024-09-07T23:29:47+03:00" level=debug msg="fetched chunk 3/24, size: 524288" uri="spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm" Sep 07 23:29:47 volumio go-librespot[2366]: time="2024-09-07T23:29:47+03:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5011 us, period size = 221 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 99 frames" Sep 07 23:29:47 volumio go-librespot[2366]: time="2024-09-07T23:29:47+03:00" level=info msg="loaded track \"Zombie\" (paused: false, position: 2ms, duration: 282804ms, prefetched: false)" uri="spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm" Sep 07 23:29:48 volumio go-librespot[2366]: time="2024-09-07T23:29:48+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:48 volumio go-librespot[2366]: time="2024-09-07T23:29:48+03:00" level=trace msg="scheduling prefetch in 253s" Sep 07 23:29:48 volumio go-librespot[2366]: time="2024-09-07T23:29:48+03:00" level=trace msg="emitting websocket event: metadata" Sep 07 23:29:48 volumio volumio[903]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","name":"Zombie","artist_names":["Saxophone Rufus"],"album_name":"Background Music","album_cover_url":"https://i.scdn.co/image/ab67616d00001e024cdd2dbbcfed452a53d123a9","position":2,"duration":282804,"release_date":"year:2020 month:10 day:5","track_number":31,"disc_number":1}} Sep 07 23:29:48 volumio go-librespot[2366]: time="2024-09-07T23:29:48+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:29:48 volumio go-librespot[2366]: time="2024-09-07T23:29:48+03:00" level=trace msg="emitting websocket event: playing" Sep 07 23:29:48 volumio volumio[903]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","play_origin":"go-librespot"}} Sep 07 23:29:48 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:48 volumio volumio[903]: SPOTIFY: {"status":"play","service":"spop","title":"Zombie","artist":"Saxophone Rufus","album":"Background Music","albumart":"https://i.scdn.co/image/ab67616d00001e024cdd2dbbcfed452a53d123a9","uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","trackType":"spotify","seek":2,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:48 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:48 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:29:48 volumio volumio[903]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Zombie","artist":"Saxophone Rufus","album":"Background Music","albumart":"https://i.scdn.co/image/ab67616d00001e024cdd2dbbcfed452a53d123a9","uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","trackType":"spotify","seek":2,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:48 volumio volumio[903]: verbose: CURRENT POSITION 26 Sep 07 23:29:48 volumio volumio[903]: info: CoreStateMachine::syncState stateService play Sep 07 23:29:48 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus stop Sep 07 23:29:48 volumio volumio[903]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","play_origin":"go-librespot"}} Sep 07 23:29:48 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:48 volumio volumio[903]: SPOTIFY: {"status":"play","service":"spop","title":"Zombie","artist":"Saxophone Rufus","album":"Background Music","albumart":"https://i.scdn.co/image/ab67616d00001e024cdd2dbbcfed452a53d123a9","uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","trackType":"spotify","seek":2,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:48 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:48 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:29:48 volumio volumio[903]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Zombie","artist":"Saxophone Rufus","album":"Background Music","albumart":"https://i.scdn.co/image/ab67616d00001e024cdd2dbbcfed452a53d123a9","uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","trackType":"spotify","seek":2,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:48 volumio volumio[903]: verbose: CURRENT POSITION 26 Sep 07 23:29:48 volumio volumio[903]: info: CoreStateMachine::syncState stateService play Sep 07 23:29:48 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus play Sep 07 23:29:48 volumio volumio[903]: info: Received an update from plugin. extracting info from payload Sep 07 23:29:48 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:48 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:29:48 volumio volumio[903]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 23:29:48 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:48 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:48 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:29:48 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:48 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:48 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:48 volumio volumio[903]: SPOTIFY: {"status":"play","service":"spop","title":"Zombie","artist":"Saxophone Rufus","album":"Background Music","albumart":"https://i.scdn.co/image/ab67616d00001e024cdd2dbbcfed452a53d123a9","uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","trackType":"spotify","seek":2,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:48 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:48 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:29:48 volumio volumio[903]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Zombie","artist":"Saxophone Rufus","album":"Background Music","albumart":"https://i.scdn.co/image/ab67616d00001e024cdd2dbbcfed452a53d123a9","uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","trackType":"spotify","seek":2,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:48 volumio volumio[903]: verbose: CURRENT POSITION 26 Sep 07 23:29:48 volumio volumio[903]: info: CoreStateMachine::syncState stateService play Sep 07 23:29:48 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus play Sep 07 23:29:48 volumio volumio[903]: info: Received an update from plugin. extracting info from payload Sep 07 23:29:48 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:48 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:29:48 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:48 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:48 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:29:48 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:48 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:48 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:48 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:29:48 volumio volumio[903]: SPOTIFY: {"status":"play","service":"spop","title":"Zombie","artist":"Saxophone Rufus","album":"Background Music","albumart":"https://i.scdn.co/image/ab67616d00001e024cdd2dbbcfed452a53d123a9","uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","trackType":"spotify","seek":2,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:48 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:29:48 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:29:48 volumio volumio[903]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Zombie","artist":"Saxophone Rufus","album":"Background Music","albumart":"https://i.scdn.co/image/ab67616d00001e024cdd2dbbcfed452a53d123a9","uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","trackType":"spotify","seek":2,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:29:48 volumio volumio[903]: verbose: CURRENT POSITION 26 Sep 07 23:29:48 volumio volumio[903]: info: CoreStateMachine::syncState stateService play Sep 07 23:29:48 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus play Sep 07 23:29:48 volumio volumio[903]: info: Received an update from plugin. extracting info from payload Sep 07 23:29:48 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:48 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:29:48 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:48 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:29:48 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:29:48 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:29:48 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:29:48 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:30:00 volumio go-librespot[2366]: time="2024-09-07T23:30:00+03:00" level=debug msg="fetched chunk 4/24, size: 524288" uri="spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm" Sep 07 23:30:02 volumio volumio[903]: info: Preload queue cleared Sep 07 23:30:02 volumio volumio[903]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 07 23:30:02 volumio volumio[903]: info: CoreStateMachine::ClearQueue Sep 07 23:30:02 volumio volumio[903]: info: CoreStateMachine::stop Sep 07 23:30:02 volumio volumio[903]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 07 23:30:02 volumio volumio[903]: info: CoreStateMachine::stPlaybackTimer Sep 07 23:30:02 volumio volumio[903]: info: CoreStateMachine::updateTrackBlock Sep 07 23:30:02 volumio volumio[903]: info: CorePlayQueue::getTrackBlock Sep 07 23:30:02 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:30:02 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:30:02 volumio volumio[903]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 23:30:02 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:30:02 volumio volumio[903]: info: CoreStateMachine::serviceStop Sep 07 23:30:02 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:30:02 volumio volumio[903]: info: CoreCommandRouter::serviceStop Sep 07 23:30:02 volumio volumio[903]: info: Spotify Stop Sep 07 23:30:02 volumio volumio[903]: SPOTIFY: SPOTIFY STOP Sep 07 23:30:02 volumio volumio[903]: SPOTIFY: {"status":"play","position":26,"title":"Zombie","artist":"Saxophone Rufus","album":"Background Music","albumart":"https://i.scdn.co/image/ab67616d0000b2734cdd2dbbcfed452a53d123a9","uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","trackType":"spotify","codec":"ogg","seek":2,"duration":282,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":91,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Sep 07 23:30:02 volumio volumio[903]: info: Sending Spotify command to local API: /player/pause Sep 07 23:30:02 volumio volumio[903]: info: CorePlayQueue::clearPlayQueue Sep 07 23:30:02 volumio volumio[903]: info: CorePlayQueue::saveQueue Sep 07 23:30:02 volumio volumio[903]: info: CoreCommandRouter::volumioPushQueue Sep 07 23:30:02 volumio volumio[903]: info: CoreStateMachine::addQueueItems Sep 07 23:30:02 volumio volumio[903]: info: CorePlayQueue::addQueueItems Sep 07 23:30:02 volumio volumio[903]: info: Preload queue cleared Sep 07 23:30:02 volumio volumio[903]: info: Adding Item to queue: spotify:user:spotify:playlist:37i9dQZF1EVGJJ3r00UGAt Sep 07 23:30:02 volumio volumio[903]: info: Exploding uri spotify:user:spotify:playlist:37i9dQZF1EVGJJ3r00UGAt in service spop Sep 07 23:30:02 volumio volumio[903]: SPOTIFY: EXPLODING URI:spotify:user:spotify:playlist:37i9dQZF1EVGJJ3r00UGAt Sep 07 23:30:02 volumio volumio[903]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Sep 07 23:30:02 volumio go-librespot[2366]: time="2024-09-07T23:30:02+03:00" level=debug msg="pause track at 14571ms" Sep 07 23:30:02 volumio go-librespot[2366]: time="2024-09-07T23:30:02+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:30:02 volumio go-librespot[2366]: time="2024-09-07T23:30:02+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 23:30:02 volumio go-librespot[2366]: time="2024-09-07T23:30:02+03:00" level=trace msg="emitting websocket event: paused" Sep 07 23:30:02 volumio volumio[903]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","play_origin":"go-librespot"}} Sep 07 23:30:02 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:30:02 volumio volumio[903]: SPOTIFY: {"status":"pause","service":"spop","title":"Zombie","artist":"Saxophone Rufus","album":"Background Music","albumart":"https://i.scdn.co/image/ab67616d00001e024cdd2dbbcfed452a53d123a9","uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","trackType":"spotify","seek":14002,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:30:02 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:30:02 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:30:02 volumio volumio[903]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Zombie","artist":"Saxophone Rufus","album":"Background Music","albumart":"https://i.scdn.co/image/ab67616d00001e024cdd2dbbcfed452a53d123a9","uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","trackType":"spotify","seek":14002,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:30:02 volumio volumio[903]: verbose: CURRENT POSITION 26 Sep 07 23:30:02 volumio volumio[903]: info: CoreStateMachine::syncState stateService pause Sep 07 23:30:02 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus stop Sep 07 23:30:02 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:30:02 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:30:02 volumio volumio[903]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 23:30:02 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:30:02 volumio volumio[903]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","play_origin":"go-librespot"}} Sep 07 23:30:02 volumio volumio[903]: SPOTIFY: PUSH STATE SPOTIFY Sep 07 23:30:02 volumio volumio[903]: SPOTIFY: {"status":"pause","service":"spop","title":"Zombie","artist":"Saxophone Rufus","album":"Background Music","albumart":"https://i.scdn.co/image/ab67616d00001e024cdd2dbbcfed452a53d123a9","uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","trackType":"spotify","seek":14002,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:30:02 volumio volumio[903]: info: CoreCommandRouter::servicePushState Sep 07 23:30:02 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:30:02 volumio volumio[903]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Zombie","artist":"Saxophone Rufus","album":"Background Music","albumart":"https://i.scdn.co/image/ab67616d00001e024cdd2dbbcfed452a53d123a9","uri":"spotify:track:77bnQRhEsVQ8ZPJ7jzEIdm","trackType":"spotify","seek":14002,"duration":282,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 07 23:30:02 volumio volumio[903]: verbose: CURRENT POSITION 26 Sep 07 23:30:02 volumio volumio[903]: info: CoreStateMachine::syncState stateService pause Sep 07 23:30:02 volumio volumio[903]: info: CoreStateMachine::syncState currentStatus stop Sep 07 23:30:02 volumio volumio[903]: info: CoreStateMachine::pushState Sep 07 23:30:02 volumio volumio[903]: info: CorePlayQueue::getTrack 26 Sep 07 23:30:02 volumio volumio[903]: info: CoreCommandRouter::volumioPushState Sep 07 23:30:02 volumio volumio[903]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 07 23:30:02 volumio volumio[903]: Error: ENOTDIR: not a directory, scandir '/tmp/peppyrunning' Sep 07 23:30:02 volumio volumio[903]: at Object.readdirSync (fs.js:1048:3) Sep 07 23:30:02 volumio volumio[903]: at rmkidsSync (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:349:11) Sep 07 23:30:02 volumio volumio[903]: at rmdirSync (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:342:7) Sep 07 23:30:02 volumio volumio[903]: at Function.rimrafSync [as sync] (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:319:62) Sep 07 23:30:02 volumio volumio[903]: at Object.removeSync (/data/plugins/user_interface/peppy_screensaver/node_modules/fs-extra/lib/remove/index.js:4:17) Sep 07 23:30:02 volumio volumio[903]: at Socket. (/data/plugins/user_interface/peppy_screensaver/index.js:225:48) Sep 07 23:30:02 volumio volumio[903]: at Socket.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) Sep 07 23:30:02 volumio volumio[903]: at Socket.onevent (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/socket.js:278:10) Sep 07 23:30:02 volumio volumio[903]: at Socket.onpacket (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/socket.js:236:12) Sep 07 23:30:02 volumio volumio[903]: at Manager. (/data/plugins/user_interface/peppy_screensaver/node_modules/component-bind/index.js:21:15) Sep 07 23:30:02 volumio volumio[903]: at Manager.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) Sep 07 23:30:02 volumio volumio[903]: at Manager.ondecoded (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/manager.js:349:8) Sep 07 23:30:02 volumio volumio[903]: at Decoder. (/data/plugins/user_interface/peppy_screensaver/node_modules/component-bind/index.js:21:15) Sep 07 23:30:02 volumio volumio[903]: at Decoder.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) Sep 07 23:30:02 volumio volumio[903]: at Decoder.add (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-parser/index.js:251:12) Sep 07 23:30:02 volumio volumio[903]: at Manager.ondata (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/manager.js:339:16) { Sep 07 23:30:02 volumio volumio[903]: errno: -20, Sep 07 23:30:02 volumio volumio[903]: syscall: 'scandir', Sep 07 23:30:02 volumio volumio[903]: code: 'ENOTDIR', Sep 07 23:30:02 volumio volumio[903]: path: '/tmp/peppyrunning' Sep 07 23:30:02 volumio volumio[903]: } Sep 07 23:30:02 volumio volumio[903]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 07 23:30:03 volumio sudo[2799]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-07 23:29 Sep 07 23:30:03 volumio sudo[2799]: 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:48:50 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="1049be5fd382035818795b7f5c38e10d"