Jun 28 19:43:03 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 28 19:43:03 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 28 19:43:03 vpmusica volumio[1267]: info: Discovery: Getting this device information Jun 28 19:43:03 vpmusica volumio[1267]: info: CoreCommandRouter::volumioGetState Jun 28 19:43:03 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 28 19:43:03 vpmusica systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jun 28 19:43:03 vpmusica dbus-daemon[689]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.438' (uid=0 pid=1046 comm="timedatectl show --property=NTPSynchronized --valu") Jun 28 19:43:03 vpmusica systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jun 28 19:43:03 vpmusica dbus-daemon[689]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 28 19:43:03 vpmusica systemd[1]: Started systemd-timedated.service - Time & Date Service. Jun 28 19:43:03 vpmusica setdatetime-helper.sh[1045]: Time is already synchronized. Jun 28 19:43:03 vpmusica systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jun 28 19:43:03 vpmusica systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jun 28 19:43:05 vpmusica go-librespot[1504]: time="2025-06-28T19:43:05+02:00" level=trace msg="sent dealer ping" Jun 28 19:43:05 vpmusica go-librespot[1504]: time="2025-06-28T19:43:05+02:00" level=trace msg="received dealer pong" Jun 28 19:43:09 vpmusica volumio[1267]: Searching plugin music_service/spop Jun 28 19:43:09 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: spop , search Jun 28 19:43:10 vpmusica volumio[1267]: info: All search sources collected, pushing search results Jun 28 19:43:12 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 28 19:43:12 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 28 19:43:12 vpmusica volumio[1267]: info: Discovery: Getting this device information Jun 28 19:43:12 vpmusica volumio[1267]: info: CoreCommandRouter::volumioGetState Jun 28 19:43:12 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 28 19:43:13 vpmusica volumio[1267]: verbose: New Socket.io Connection to 192.168.100.51:3000 from 192.168.100.37 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 11 Jun 28 19:43:22 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 28 19:43:22 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 28 19:43:22 vpmusica volumio[1267]: info: Discovery: Getting this device information Jun 28 19:43:22 vpmusica volumio[1267]: info: CoreCommandRouter::volumioGetState Jun 28 19:43:22 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 28 19:43:24 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Jun 28 19:43:24 vpmusica volumio[1267]: info: In handleBrowseUri, curUri=spotify:album:43NFJfCi7NfjPeKkzGvYV7 Jun 28 19:43:25 vpmusica volumio[1267]: info: Preload queue cleared Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:5j3SdyjQrT0myANQybhBWn Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:5JYds8Xn7inmXSnvcuFno3 Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:4obmf0WqbLqFPEUvh45qI6 Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:3ZW2po7bakHkQNjofeRE0N Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:2IzACNi7l8QE1xGor5qqHD Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:797LTvxnilxPDfEGtIW25b Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:6GLvwV7E8N2D1C9eptY8Hd Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:7rlkSfbEUfuej0zSMrYN9L Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:0w5nB3LsqFg1R05wO0mQZA Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:5Wua3xZylYy8GGu79Y1lPx Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:7tfqjIADPc0O1OcrIRdNAA Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:7j6RDpLhEdeCHSeAjSgfBl Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:4OVPZnr6MfSqxBsWGza0X0 Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:2ARhU24oA8PV7kX0eIYAs4 Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:2zxX2yJn2XQvj6qEEyETCp Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:7ydSvadJXaxKseCmovJx7T Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:4U5yCbKWI04aRlDDtKS8qD Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:38IWN0vjs75MJT3jkrRNW5 Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:2eYIyCYb3TfPdZcQILtMSq Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:7kOMoDXaeq6JvcobdQ7t7p Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:0hMozIcjL7J6QkKthUZ2nl Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:0G5x1iXBMc90c4adlhwn9s Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:0OddHt3qGin0BpYG1jUn1i Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:5vtquFHfPFrdp3ZgLL3a93 Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:6KhAk06XCiOQLMMo9w7Pfy Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:2qVs71IWIb52k7PXQ3gKHj Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:1iVJgg5Q2FihclZgODTg98 Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:0kxaO57vDBci1Y3URA0AyX Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:7pKbSMZUzyhBvercFVyDm5 Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:68jbynkbiMrrHGmZcgVIQs Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:2BsbrouknmJmFimew1vE8F Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:6lGZPviWMmeae0rFMj2EFc Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:4t6pUoS0NfRcy3WmjPCWad Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:5V0oxY54PSmVrtTtb2qW4U Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:4ECgT7KE9zGa9Qb7tj7crC Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:1ljis7wIAGw23ZD1hIgi7K Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:0NvApIeNbu7iVOedNnVSDQ Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:3yW4RDB1GWGjOualSj8iID Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:3NNkt41nn4qHZDOQ2hnCK2 Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:0NXySg79vgXqiWhxam7c95 Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:7smnjrzpbxsP2e50hJQ1Qz Jun 28 19:43:25 vpmusica volumio[1267]: info: Preloading song: spotify:track:4fzTC7kUbm54PWexytinmU Jun 28 19:43:25 vpmusica volumio[1267]: info: Exploding uri spotify:track:5j3SdyjQrT0myANQybhBWn in service spop Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:5j3SdyjQrT0myANQybhBWn Jun 28 19:43:25 vpmusica volumio[1267]: info: Exploding uri spotify:track:5JYds8Xn7inmXSnvcuFno3 in service spop Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:5JYds8Xn7inmXSnvcuFno3 Jun 28 19:43:25 vpmusica volumio[1267]: info: Exploding uri spotify:track:4obmf0WqbLqFPEUvh45qI6 in service spop Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:4obmf0WqbLqFPEUvh45qI6 Jun 28 19:43:25 vpmusica volumio[1267]: info: Exploding uri spotify:track:3ZW2po7bakHkQNjofeRE0N in service spop Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:3ZW2po7bakHkQNjofeRE0N Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5j3SdyjQrT0myANQybhBWn","service":"spop","name":"Hollywood","artist":"Lana Jurcevic","album":"Zabavni Mix Hitovi","type":"song","duration":217,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5JYds8Xn7inmXSnvcuFno3","service":"spop","name":"Kaktus","artist":"Lidija Bačić","album":"Zabavni Mix Hitovi","type":"song","duration":231,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:25 vpmusica volumio[1267]: info: Exploding uri spotify:track:2IzACNi7l8QE1xGor5qqHD in service spop Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:2IzACNi7l8QE1xGor5qqHD Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4obmf0WqbLqFPEUvh45qI6","service":"spop","name":"Zavela Me Ana","artist":"Ts Mejaši","album":"Zabavni Mix Hitovi","type":"song","duration":182,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:25 vpmusica volumio[1267]: info: Exploding uri spotify:track:797LTvxnilxPDfEGtIW25b in service spop Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:797LTvxnilxPDfEGtIW25b Jun 28 19:43:25 vpmusica volumio[1267]: info: Exploding uri spotify:track:6GLvwV7E8N2D1C9eptY8Hd in service spop Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:6GLvwV7E8N2D1C9eptY8Hd Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3ZW2po7bakHkQNjofeRE0N","service":"spop","name":"Karanfili","artist":"Nives Celzijus","album":"Zabavni Mix Hitovi","type":"song","duration":178,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2IzACNi7l8QE1xGor5qqHD","service":"spop","name":"Jao Meni","artist":"Ivana Kovač","album":"Zabavni Mix Hitovi","type":"song","duration":202,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:25 vpmusica volumio[1267]: info: Exploding uri spotify:track:7rlkSfbEUfuej0zSMrYN9L in service spop Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:7rlkSfbEUfuej0zSMrYN9L Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:797LTvxnilxPDfEGtIW25b","service":"spop","name":"Crveni Ferrari","artist":"Mladen Grdović","album":"Zabavni Mix Hitovi","type":"song","duration":200,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:25 vpmusica volumio[1267]: info: Exploding uri spotify:track:0w5nB3LsqFg1R05wO0mQZA in service spop Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:0w5nB3LsqFg1R05wO0mQZA Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6GLvwV7E8N2D1C9eptY8Hd","service":"spop","name":"Nitko Nema Dva Života","artist":"Drazen Zecic","album":"Zabavni Mix Hitovi","type":"song","duration":217,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:25 vpmusica volumio[1267]: info: Exploding uri spotify:track:5Wua3xZylYy8GGu79Y1lPx in service spop Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:5Wua3xZylYy8GGu79Y1lPx Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7rlkSfbEUfuej0zSMrYN9L","service":"spop","name":"Odavno Više Ne Plačem Zbog Tebe","artist":"Mišo Kovač","album":"Zabavni Mix Hitovi","type":"song","duration":196,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:25 vpmusica volumio[1267]: info: Exploding uri spotify:track:7tfqjIADPc0O1OcrIRdNAA in service spop Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:7tfqjIADPc0O1OcrIRdNAA Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0w5nB3LsqFg1R05wO0mQZA","service":"spop","name":"Večeras Je Naša Fešta","artist":"Tomislav Ivčić","album":"Zabavni Mix Hitovi","type":"song","duration":174,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:25 vpmusica volumio[1267]: info: Exploding uri spotify:track:7j6RDpLhEdeCHSeAjSgfBl in service spop Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:7j6RDpLhEdeCHSeAjSgfBl Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5Wua3xZylYy8GGu79Y1lPx","service":"spop","name":"Ispod Škura","artist":"Zaratino Band","album":"Zabavni Mix Hitovi","type":"song","duration":207,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:25 vpmusica volumio[1267]: info: Exploding uri spotify:track:4OVPZnr6MfSqxBsWGza0X0 in service spop Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:4OVPZnr6MfSqxBsWGza0X0 Jun 28 19:43:25 vpmusica volumio[1267]: info: Exploding uri spotify:track:2ARhU24oA8PV7kX0eIYAs4 in service spop Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:2ARhU24oA8PV7kX0eIYAs4 Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7tfqjIADPc0O1OcrIRdNAA","service":"spop","name":"Gamele","artist":"Tonči @ Madre Badessa","album":"Zabavni Mix Hitovi","type":"song","duration":260,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:25 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7j6RDpLhEdeCHSeAjSgfBl","service":"spop","name":"Biži Sa Mnom Mala Moja","artist":"Giuliano","album":"Zabavni Mix Hitovi","type":"song","duration":232,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:2zxX2yJn2XQvj6qEEyETCp in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:2zxX2yJn2XQvj6qEEyETCp Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4OVPZnr6MfSqxBsWGza0X0","service":"spop","name":"Ma Daj, Obuci Levisice","artist":"Daniel Popović","album":"Zabavni Mix Hitovi","type":"song","duration":167,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:7ydSvadJXaxKseCmovJx7T in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:7ydSvadJXaxKseCmovJx7T Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2ARhU24oA8PV7kX0eIYAs4","service":"spop","name":"Nima Splita Do Splita","artist":"Tereza Kesovija","album":"Zabavni Mix Hitovi","type":"song","duration":131,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:4U5yCbKWI04aRlDDtKS8qD in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:4U5yCbKWI04aRlDDtKS8qD Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2zxX2yJn2XQvj6qEEyETCp","service":"spop","name":"Nadalina","artist":"Oliver Dragojevic","album":"Zabavni Mix Hitovi","type":"song","duration":279,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:38IWN0vjs75MJT3jkrRNW5 in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:38IWN0vjs75MJT3jkrRNW5 Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7ydSvadJXaxKseCmovJx7T","service":"spop","name":"Na Obali","artist":"Jasna Zlokic","album":"Zabavni Mix Hitovi","type":"song","duration":232,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:2eYIyCYb3TfPdZcQILtMSq in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:2eYIyCYb3TfPdZcQILtMSq Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4U5yCbKWI04aRlDDtKS8qD","service":"spop","name":"Vino Na Usnama - Live At Cibona","artist":"Vlado Kalember","album":"Zabavni Mix Hitovi","type":"song","duration":256,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:7kOMoDXaeq6JvcobdQ7t7p in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:7kOMoDXaeq6JvcobdQ7t7p Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:38IWN0vjs75MJT3jkrRNW5","service":"spop","name":"Za Dobra Stara Vremena","artist":"Novi Fosili","album":"Zabavni Mix Hitovi","type":"song","duration":236,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:0hMozIcjL7J6QkKthUZ2nl in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:0hMozIcjL7J6QkKthUZ2nl Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2eYIyCYb3TfPdZcQILtMSq","service":"spop","name":"Željo Moja","artist":"Doris Dragović","album":"Zabavni Mix Hitovi","type":"song","duration":178,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:0G5x1iXBMc90c4adlhwn9s in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:0G5x1iXBMc90c4adlhwn9s Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7kOMoDXaeq6JvcobdQ7t7p","service":"spop","name":"Kad Se Prijatelji Rastaju","artist":"Jasmin Stavros","album":"Zabavni Mix Hitovi","type":"song","duration":243,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:0OddHt3qGin0BpYG1jUn1i in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:0OddHt3qGin0BpYG1jUn1i Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:5vtquFHfPFrdp3ZgLL3a93 in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:5vtquFHfPFrdp3ZgLL3a93 Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0G5x1iXBMc90c4adlhwn9s","service":"spop","name":"Uvik Isti","artist":"Petar Grašo","album":"Zabavni Mix Hitovi","type":"song","duration":251,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:6KhAk06XCiOQLMMo9w7Pfy in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:6KhAk06XCiOQLMMo9w7Pfy Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0hMozIcjL7J6QkKthUZ2nl","service":"spop","name":"Ostala Si Uvijek Ista","artist":"Toše Proeski","album":"Zabavni Mix Hitovi","type":"song","duration":255,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0OddHt3qGin0BpYG1jUn1i","service":"spop","name":"Zove, Zove, Jole, Jole","artist":"Jole","album":"Zabavni Mix Hitovi","type":"song","duration":205,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:2qVs71IWIb52k7PXQ3gKHj in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:2qVs71IWIb52k7PXQ3gKHj Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5vtquFHfPFrdp3ZgLL3a93","service":"spop","name":"Jenu Noć","artist":"Alen Vitasovic","album":"Zabavni Mix Hitovi","type":"song","duration":231,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:1iVJgg5Q2FihclZgODTg98 in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:1iVJgg5Q2FihclZgODTg98 Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6KhAk06XCiOQLMMo9w7Pfy","service":"spop","name":"Nisi Ti Više Crno Vino","artist":"Dalibor Brun","album":"Zabavni Mix Hitovi","type":"song","duration":207,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:0kxaO57vDBci1Y3URA0AyX in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:0kxaO57vDBci1Y3URA0AyX Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:7pKbSMZUzyhBvercFVyDm5 in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:7pKbSMZUzyhBvercFVyDm5 Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2qVs71IWIb52k7PXQ3gKHj","service":"spop","name":"Rock Me","artist":"Riva","album":"Zabavni Mix Hitovi","type":"song","duration":163,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:68jbynkbiMrrHGmZcgVIQs in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:68jbynkbiMrrHGmZcgVIQs Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1iVJgg5Q2FihclZgODTg98","service":"spop","name":"Hajde Da Ludujemo","artist":"Tajci","album":"Zabavni Mix Hitovi","type":"song","duration":182,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0kxaO57vDBci1Y3URA0AyX","service":"spop","name":"Pjevam Danju,Pjevam Noću","artist":"Zdravko Čolić","album":"Zabavni Mix Hitovi","type":"song","duration":240,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:2BsbrouknmJmFimew1vE8F in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:2BsbrouknmJmFimew1vE8F Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7pKbSMZUzyhBvercFVyDm5","service":"spop","name":"Mala Je Dala","artist":"Severina","album":"Zabavni Mix Hitovi","type":"song","duration":231,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:6lGZPviWMmeae0rFMj2EFc in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:6lGZPviWMmeae0rFMj2EFc Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:68jbynkbiMrrHGmZcgVIQs","service":"spop","name":"Dolje Na Koljena","artist":"Vesna Pisarovic","album":"Zabavni Mix Hitovi","type":"song","duration":208,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:4t6pUoS0NfRcy3WmjPCWad in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:4t6pUoS0NfRcy3WmjPCWad Jun 28 19:43:26 vpmusica volumio[1267]: info: Exploding uri spotify:track:5V0oxY54PSmVrtTtb2qW4U in service spop Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:5V0oxY54PSmVrtTtb2qW4U Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2BsbrouknmJmFimew1vE8F","service":"spop","name":"Dvije Lude","artist":"Mate Bulic","album":"Zabavni Mix Hitovi","type":"song","duration":250,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:26 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6lGZPviWMmeae0rFMj2EFc","service":"spop","name":"Ja Sam Uvijek Loše Birao","artist":"Kumovi","album":"Zabavni Mix Hitovi","type":"song","duration":203,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:27 vpmusica volumio[1267]: info: Exploding uri spotify:track:4ECgT7KE9zGa9Qb7tj7crC in service spop Jun 28 19:43:27 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:4ECgT7KE9zGa9Qb7tj7crC Jun 28 19:43:27 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4t6pUoS0NfRcy3WmjPCWad","service":"spop","name":"Rajske Kočije","artist":"Sinisa Vuco","album":"Zabavni Mix Hitovi","type":"song","duration":228,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:27 vpmusica volumio[1267]: info: Exploding uri spotify:track:1ljis7wIAGw23ZD1hIgi7K in service spop Jun 28 19:43:27 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:1ljis7wIAGw23ZD1hIgi7K Jun 28 19:43:27 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5V0oxY54PSmVrtTtb2qW4U","service":"spop","name":"Ružmarin","artist":"Vladimir Kočiš Zec","album":"Zabavni Mix Hitovi","type":"song","duration":230,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:27 vpmusica volumio[1267]: info: Exploding uri spotify:track:0NvApIeNbu7iVOedNnVSDQ in service spop Jun 28 19:43:27 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:0NvApIeNbu7iVOedNnVSDQ Jun 28 19:43:27 vpmusica volumio[1267]: info: Exploding uri spotify:track:3yW4RDB1GWGjOualSj8iID in service spop Jun 28 19:43:27 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:3yW4RDB1GWGjOualSj8iID Jun 28 19:43:27 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4ECgT7KE9zGa9Qb7tj7crC","service":"spop","name":"Laži Me","artist":"Alka Vuica","album":"Zabavni Mix Hitovi","type":"song","duration":219,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:27 vpmusica volumio[1267]: info: Exploding uri spotify:track:3NNkt41nn4qHZDOQ2hnCK2 in service spop Jun 28 19:43:27 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:3NNkt41nn4qHZDOQ2hnCK2 Jun 28 19:43:27 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1ljis7wIAGw23ZD1hIgi7K","service":"spop","name":"Ti Možeš Lagat","artist":"Danijela Martinovic","album":"Zabavni Mix Hitovi","type":"song","duration":193,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:27 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0NvApIeNbu7iVOedNnVSDQ","service":"spop","name":"No, No, No","artist":"Magazin","album":"Zabavni Mix Hitovi","type":"song","duration":251,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:27 vpmusica volumio[1267]: info: Exploding uri spotify:track:0NXySg79vgXqiWhxam7c95 in service spop Jun 28 19:43:27 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:0NXySg79vgXqiWhxam7c95 Jun 28 19:43:27 vpmusica volumio[1267]: info: Exploding uri spotify:track:7smnjrzpbxsP2e50hJQ1Qz in service spop Jun 28 19:43:27 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:7smnjrzpbxsP2e50hJQ1Qz Jun 28 19:43:27 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3NNkt41nn4qHZDOQ2hnCK2","service":"spop","name":"Priđi Bez Razloga","artist":"ET","album":"Zabavni Mix Hitovi","type":"song","duration":257,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:27 vpmusica volumio[1267]: info: Exploding uri spotify:track:4fzTC7kUbm54PWexytinmU in service spop Jun 28 19:43:27 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:track:4fzTC7kUbm54PWexytinmU Jun 28 19:43:27 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3yW4RDB1GWGjOualSj8iID","service":"spop","name":"Buka, Galama","artist":"Petra Kovačević","album":"Zabavni Mix Hitovi","type":"song","duration":231,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:27 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0NXySg79vgXqiWhxam7c95","service":"spop","name":"Subota","artist":"Karma","album":"Zabavni Mix Hitovi","type":"song","duration":246,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:27 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7smnjrzpbxsP2e50hJQ1Qz","service":"spop","name":"Oduzimaš Mi Dah","artist":"Colonia","album":"Zabavni Mix Hitovi","type":"song","duration":260,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:27 vpmusica volumio[1267]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4fzTC7kUbm54PWexytinmU","service":"spop","name":"Život Je Čudo","artist":"Jelena Rozga","album":"Zabavni Mix Hitovi","type":"song","duration":236,"albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 28 19:43:33 vpmusica systemd[1]: systemd-timedated.service: Deactivated successfully. Jun 28 19:43:35 vpmusica volumio[1267]: info: Preload queue cleared Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::ClearQueue Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::stop Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::stPlaybackTimer Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::updateTrackBlock Jun 28 19:43:35 vpmusica volumio[1267]: info: CorePlayQueue::getTrackBlock Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 3 Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::serviceStop Jun 28 19:43:35 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 3 Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::serviceStop Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 28 19:43:35 vpmusica volumio[1267]: info: ControllerMpd::stop Jun 28 19:43:35 vpmusica volumio[1267]: verbose: ControllerMpd::sendMpdCommand stop Jun 28 19:43:35 vpmusica volumio[1267]: info: CorePlayQueue::clearPlayQueue Jun 28 19:43:35 vpmusica volumio[1267]: info: CorePlayQueue::saveQueue Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushQueue Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::addQueueItems Jun 28 19:43:35 vpmusica volumio[1267]: info: CorePlayQueue::addQueueItems Jun 28 19:43:35 vpmusica volumio[1267]: info: Preload queue cleared Jun 28 19:43:35 vpmusica volumio[1267]: info: Adding Item to queue: spotify:album:43NFJfCi7NfjPeKkzGvYV7 Jun 28 19:43:35 vpmusica volumio[1267]: info: Exploding uri spotify:album:43NFJfCi7NfjPeKkzGvYV7 in service spop Jun 28 19:43:35 vpmusica volumio[1267]: SPOTIFY: EXPLODING URI:spotify:album:43NFJfCi7NfjPeKkzGvYV7 Jun 28 19:43:35 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:43:35 vpmusica volumio[1267]: info: Jun 28 19:43:35 vpmusica volumio[1267]: ---------------------------- MPD announces state update: player Jun 28 19:43:35 vpmusica volumio[1267]: info: sendMpdCommand stop took 18 milliseconds Jun 28 19:43:35 vpmusica volumio[1267]: info: ControllerMpd::getState Jun 28 19:43:35 vpmusica volumio[1267]: verbose: ControllerMpd::sendMpdCommand status Jun 28 19:43:35 vpmusica volumio[1267]: info: Jun 28 19:43:35 vpmusica volumio[1267]: ---------------------------- MPD announces state update: player Jun 28 19:43:35 vpmusica volumio[1267]: info: ControllerMpd::getState Jun 28 19:43:35 vpmusica volumio[1267]: verbose: ControllerMpd::sendMpdCommand status Jun 28 19:43:35 vpmusica volumio[1267]: info: Jun 28 19:43:35 vpmusica volumio[1267]: ---------------------------- MPD announces state update: player Jun 28 19:43:35 vpmusica volumio[1267]: info: ControllerMpd::getState Jun 28 19:43:35 vpmusica volumio[1267]: verbose: ControllerMpd::sendMpdCommand status Jun 28 19:43:35 vpmusica volumio[1267]: info: sendMpdCommand status took 2 milliseconds Jun 28 19:43:35 vpmusica volumio[1267]: info: sendMpdCommand status took 2 milliseconds Jun 28 19:43:35 vpmusica volumio[1267]: info: sendMpdCommand status took 1 milliseconds Jun 28 19:43:35 vpmusica volumio[1267]: verbose: ControllerMpd::parseState Jun 28 19:43:35 vpmusica volumio[1267]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 28 19:43:35 vpmusica volumio[1267]: verbose: ControllerMpd::parseState Jun 28 19:43:35 vpmusica volumio[1267]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 28 19:43:35 vpmusica volumio[1267]: verbose: ControllerMpd::parseState Jun 28 19:43:35 vpmusica volumio[1267]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 28 19:43:35 vpmusica volumio[1267]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 28 19:43:35 vpmusica volumio[1267]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 28 19:43:35 vpmusica volumio[1267]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 28 19:43:35 vpmusica volumio[1267]: verbose: ControllerMpd::parseTrackInfo Jun 28 19:43:35 vpmusica volumio[1267]: verbose: ControllerMpd::parseTrackInfo Jun 28 19:43:35 vpmusica volumio[1267]: verbose: ControllerMpd::parseTrackInfo Jun 28 19:43:35 vpmusica volumio[1267]: info: ControllerMpd::pushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::servicePushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 3 Jun 28 19:43:35 vpmusica volumio[1267]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Top 50 Beautiful Instrumental Guitar Love Songs - Romantic Melodies for Soulful Peace","artist":"Oceanic Guitar","album":"YouTube","uri":"https://rr4---sn-uiu-15be.googlevideo.com/videoplayback?expire=1751153463&ei=1yZgaKLuBfP_i9oP-ue4mA8&ip=93.138.37.232&id=o-ADCRDtSFkJ5b-BfoBh_ZjYYYtcyaaAtagvpOhP2MAOZa&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1751131863%2C&mh=cB&mm=31%2C29&mn=sn-uiu-15be%2Csn-c0q7lns7&ms=au%2Crdu&mv=m&mvi=4&pl=16&rms=au%2Cau&initcwndbps=1573750&bui=AY1jyLOmEtH_wfqvZv0RAe72y1PvVKcECNhw92a7JF-6q0P2Ttg6QEk-j4UIU_iWMrp1SMC6rIi_u63G&spc=l3OVKY4oPlWL8b41laJOHiAW-xbwreMvCDiqrFloogS7LgQAzfFXGg&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=gksXWWGPYm6Y3oe7ixvnSHcQ&rqh=1&gir=yes&clen=1850744462&dur=92968.661&lmt=1717746330421878&mt=1751131288&fvip=2&keepalive=yes&c=WEB_EMBEDDED_PLAYER&sefc=1&txp=5432434&n=TCeE8fEIDQ_lOg&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRQIhAMD8U8ywCPtJqHbAUgxI_QglA4Sek1JTZq_eMQxyOUHpAiBW_n68zWmUpHxuUsQi-gdYbZMoSLPP1OeaLrT3Z1WlSg%3D%3D&sig=AJfQdSswRQIhALvuc6ZqJDuxZswZVe0TaTUscXFr1Gli-mdoYXm_CFGnAiBt8h--IHhXLzWcUXyIPwD4jsx_Ewhh9QohTfSq-5lT8A%3D%3D&pot=MpgBwhb6ULMkxULCKnJk9VpQYwiBoxL07BUnsd3A8L--0LaQHT4kVY3vFBKaBM_jiv_KJ6N6uY3pSU5EEPDzkoG7-zJePigdeRd61RhL69kGtODgU22nvdPRu5yOrliykcfzAt9no18Zqb_oYVzPgG8wOYC9BTksunrxzgfoITMqDvr9Bc9Z6Y1urFGWwV7o9P1MzkqoK81oo30%3D&cver=1.20250219.01.00&t.YouTube","trackType":"YouTube"} Jun 28 19:43:35 vpmusica volumio[1267]: verbose: CURRENT POSITION 3 Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::syncState stateService stop Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::syncState currentStatus stop Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:43:35 vpmusica volumio[1267]: info: No code Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:43:35 vpmusica volumio[1267]: info: ControllerMpd::pushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::servicePushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 3 Jun 28 19:43:35 vpmusica volumio[1267]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Top 50 Beautiful Instrumental Guitar Love Songs - Romantic Melodies for Soulful Peace","artist":"Oceanic Guitar","album":"YouTube","uri":"https://rr4---sn-uiu-15be.googlevideo.com/videoplayback?expire=1751153463&ei=1yZgaKLuBfP_i9oP-ue4mA8&ip=93.138.37.232&id=o-ADCRDtSFkJ5b-BfoBh_ZjYYYtcyaaAtagvpOhP2MAOZa&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1751131863%2C&mh=cB&mm=31%2C29&mn=sn-uiu-15be%2Csn-c0q7lns7&ms=au%2Crdu&mv=m&mvi=4&pl=16&rms=au%2Cau&initcwndbps=1573750&bui=AY1jyLOmEtH_wfqvZv0RAe72y1PvVKcECNhw92a7JF-6q0P2Ttg6QEk-j4UIU_iWMrp1SMC6rIi_u63G&spc=l3OVKY4oPlWL8b41laJOHiAW-xbwreMvCDiqrFloogS7LgQAzfFXGg&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=gksXWWGPYm6Y3oe7ixvnSHcQ&rqh=1&gir=yes&clen=1850744462&dur=92968.661&lmt=1717746330421878&mt=1751131288&fvip=2&keepalive=yes&c=WEB_EMBEDDED_PLAYER&sefc=1&txp=5432434&n=TCeE8fEIDQ_lOg&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRQIhAMD8U8ywCPtJqHbAUgxI_QglA4Sek1JTZq_eMQxyOUHpAiBW_n68zWmUpHxuUsQi-gdYbZMoSLPP1OeaLrT3Z1WlSg%3D%3D&sig=AJfQdSswRQIhALvuc6ZqJDuxZswZVe0TaTUscXFr1Gli-mdoYXm_CFGnAiBt8h--IHhXLzWcUXyIPwD4jsx_Ewhh9QohTfSq-5lT8A%3D%3D&pot=MpgBwhb6ULMkxULCKnJk9VpQYwiBoxL07BUnsd3A8L--0LaQHT4kVY3vFBKaBM_jiv_KJ6N6uY3pSU5EEPDzkoG7-zJePigdeRd61RhL69kGtODgU22nvdPRu5yOrliykcfzAt9no18Zqb_oYVzPgG8wOYC9BTksunrxzgfoITMqDvr9Bc9Z6Y1urFGWwV7o9P1MzkqoK81oo30%3D&cver=1.20250219.01.00&t.YouTube","trackType":"YouTube"} Jun 28 19:43:35 vpmusica volumio[1267]: verbose: CURRENT POSITION 3 Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::syncState stateService stop Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::syncState currentStatus stop Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:43:35 vpmusica volumio[1267]: info: No code Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:43:35 vpmusica volumio[1267]: info: ControllerMpd::pushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::servicePushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 3 Jun 28 19:43:35 vpmusica volumio[1267]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Top 50 Beautiful Instrumental Guitar Love Songs - Romantic Melodies for Soulful Peace","artist":"Oceanic Guitar","album":"YouTube","uri":"https://rr4---sn-uiu-15be.googlevideo.com/videoplayback?expire=1751153463&ei=1yZgaKLuBfP_i9oP-ue4mA8&ip=93.138.37.232&id=o-ADCRDtSFkJ5b-BfoBh_ZjYYYtcyaaAtagvpOhP2MAOZa&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1751131863%2C&mh=cB&mm=31%2C29&mn=sn-uiu-15be%2Csn-c0q7lns7&ms=au%2Crdu&mv=m&mvi=4&pl=16&rms=au%2Cau&initcwndbps=1573750&bui=AY1jyLOmEtH_wfqvZv0RAe72y1PvVKcECNhw92a7JF-6q0P2Ttg6QEk-j4UIU_iWMrp1SMC6rIi_u63G&spc=l3OVKY4oPlWL8b41laJOHiAW-xbwreMvCDiqrFloogS7LgQAzfFXGg&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=gksXWWGPYm6Y3oe7ixvnSHcQ&rqh=1&gir=yes&clen=1850744462&dur=92968.661&lmt=1717746330421878&mt=1751131288&fvip=2&keepalive=yes&c=WEB_EMBEDDED_PLAYER&sefc=1&txp=5432434&n=TCeE8fEIDQ_lOg&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRQIhAMD8U8ywCPtJqHbAUgxI_QglA4Sek1JTZq_eMQxyOUHpAiBW_n68zWmUpHxuUsQi-gdYbZMoSLPP1OeaLrT3Z1WlSg%3D%3D&sig=AJfQdSswRQIhALvuc6ZqJDuxZswZVe0TaTUscXFr1Gli-mdoYXm_CFGnAiBt8h--IHhXLzWcUXyIPwD4jsx_Ewhh9QohTfSq-5lT8A%3D%3D&pot=MpgBwhb6ULMkxULCKnJk9VpQYwiBoxL07BUnsd3A8L--0LaQHT4kVY3vFBKaBM_jiv_KJ6N6uY3pSU5EEPDzkoG7-zJePigdeRd61RhL69kGtODgU22nvdPRu5yOrliykcfzAt9no18Zqb_oYVzPgG8wOYC9BTksunrxzgfoITMqDvr9Bc9Z6Y1urFGWwV7o9P1MzkqoK81oo30%3D&cver=1.20250219.01.00&t.YouTube","trackType":"YouTube"} Jun 28 19:43:35 vpmusica volumio[1267]: verbose: CURRENT POSITION 3 Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::syncState stateService stop Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::syncState currentStatus stop Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:43:35 vpmusica volumio[1267]: info: No code Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:43:35 vpmusica volumio[1267]: info: ------------------------------ 29ms Jun 28 19:43:35 vpmusica volumio[1267]: info: ------------------------------ 29ms Jun 28 19:43:35 vpmusica volumio[1267]: info: ------------------------------ 28ms Jun 28 19:43:35 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:43:35 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:43:35 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:43:35 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:43:35 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:43:35 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:43:35 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:43:35 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:43:35 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushQueue Jun 28 19:43:35 vpmusica volumio[1267]: info: CorePlayQueue::saveQueue Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::updateTrackBlock Jun 28 19:43:35 vpmusica volumio[1267]: info: CorePlayQueue::getTrackBlock Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPlay Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::play index 0 Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::stop Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::play index undefined Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 28 19:43:35 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 0 Jun 28 19:43:35 vpmusica volumio[1267]: info: CoreStateMachine::startPlaybackTimer Jun 28 19:43:35 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 0 Jun 28 19:43:35 vpmusica volumio[1267]: info: [1751132615343] ControllerSpotify::clearAddPlayTrack Jun 28 19:43:35 vpmusica volumio[1267]: info: Sending Spotify command with payload to local API: /player/play Jun 28 19:43:35 vpmusica go-librespot[1504]: time="2025-06-28T19:43:35+02:00" level=debug msg="renewing login5 access token" Jun 28 19:43:35 vpmusica go-librespot[1504]: time="2025-06-28T19:43:35+02:00" level=info msg="authenticated Login5 as 31fvshbdicfgzm2wuf7kfb4tz7yy" Jun 28 19:43:35 vpmusica go-librespot[1504]: time="2025-06-28T19:43:35+02:00" level=debug msg="resolved context of track" uri="spotify:track:5j3SdyjQrT0myANQybhBWn" Jun 28 19:43:35 vpmusica go-librespot[1504]: time="2025-06-28T19:43:35+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:5j3SdyjQrT0myANQybhBWn" Jun 28 19:43:35 vpmusica go-librespot[1504]: time="2025-06-28T19:43:35+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:5j3SdyjQrT0myANQybhBWn" Jun 28 19:43:35 vpmusica go-librespot[1504]: time="2025-06-28T19:43:35+02:00" level=trace msg="received accesspoint ping" Jun 28 19:43:35 vpmusica go-librespot[1504]: time="2025-06-28T19:43:35+02:00" level=trace msg="received accesspoint pong ack" Jun 28 19:43:35 vpmusica go-librespot[1504]: time="2025-06-28T19:43:35+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 28 19:43:35 vpmusica go-librespot[1504]: time="2025-06-28T19:43:35+02:00" level=trace msg="emitting websocket event: will_play" Jun 28 19:43:35 vpmusica volumio[1267]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5j3SdyjQrT0myANQybhBWn","play_origin":"go-librespot"}} Jun 28 19:43:35 vpmusica go-librespot[1504]: time="2025-06-28T19:43:35+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 28 19:43:35 vpmusica go-librespot[1504]: time="2025-06-28T19:43:35+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1375" Jun 28 19:43:35 vpmusica go-librespot[1504]: time="2025-06-28T19:43:35+02:00" level=debug msg="selected format OGG_VORBIS_320 (1a2e1290b313fa139caacd596fafa06ae9be6bd4)" uri="spotify:track:5j3SdyjQrT0myANQybhBWn" Jun 28 19:43:35 vpmusica go-librespot[1504]: time="2025-06-28T19:43:35+02:00" level=debug msg="requested aes key for file 1a2e1290b313fa139caacd596fafa06ae9be6bd4, gid: 5j3SdyjQrT0myANQybhBWn" Jun 28 19:43:35 vpmusica go-librespot[1504]: time="2025-06-28T19:43:35+02:00" level=trace msg="sent dealer ping" Jun 28 19:43:35 vpmusica go-librespot[1504]: time="2025-06-28T19:43:35+02:00" level=trace msg="received dealer pong" Jun 28 19:43:36 vpmusica go-librespot[1504]: time="2025-06-28T19:43:36+02:00" level=debug msg="fetched first chunk of 19, total size is 9552387 bytes" uri="spotify:track:5j3SdyjQrT0myANQybhBWn" Jun 28 19:43:36 vpmusica go-librespot[1504]: time="2025-06-28T19:43:36+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames" Jun 28 19:43:36 vpmusica go-librespot[1504]: time="2025-06-28T19:43:36+02:00" level=info msg="loaded track \"Hollywood\" (paused: false, position: 0ms, duration: 217653ms, prefetched: false)" uri="spotify:track:5j3SdyjQrT0myANQybhBWn" Jun 28 19:43:36 vpmusica go-librespot[1504]: time="2025-06-28T19:43:36+02:00" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:5j3SdyjQrT0myANQybhBWn" Jun 28 19:43:36 vpmusica go-librespot[1504]: time="2025-06-28T19:43:36+02:00" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:5j3SdyjQrT0myANQybhBWn" Jun 28 19:43:36 vpmusica go-librespot[1504]: time="2025-06-28T19:43:36+02:00" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:5j3SdyjQrT0myANQybhBWn" Jun 28 19:43:36 vpmusica go-librespot[1504]: time="2025-06-28T19:43:36+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 28 19:43:36 vpmusica go-librespot[1504]: time="2025-06-28T19:43:36+02:00" level=trace msg="scheduling prefetch in 187s" Jun 28 19:43:36 vpmusica go-librespot[1504]: time="2025-06-28T19:43:36+02:00" level=trace msg="emitting websocket event: metadata" Jun 28 19:43:36 vpmusica volumio[1267]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5j3SdyjQrT0myANQybhBWn","name":"Hollywood","artist_names":["Lana Jurcevic"],"album_name":"Zabavni Mix Hitovi","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","position":0,"duration":217653,"release_date":"year:2015 month:4 day:17","track_number":1,"disc_number":1}} Jun 28 19:43:36 vpmusica go-librespot[1504]: time="2025-06-28T19:43:36+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 28 19:43:36 vpmusica go-librespot[1504]: time="2025-06-28T19:43:36+02:00" level=trace msg="emitting websocket event: playing" Jun 28 19:43:36 vpmusica volumio[1267]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5j3SdyjQrT0myANQybhBWn","play_origin":"go-librespot"}} Jun 28 19:43:36 vpmusica volumio[1267]: SPOTIFY: PUSH STATE SPOTIFY Jun 28 19:43:36 vpmusica volumio[1267]: SPOTIFY: {"status":"play","service":"spop","title":"Hollywood","artist":"Lana Jurcevic","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","uri":"spotify:track:5j3SdyjQrT0myANQybhBWn","trackType":"spotify","seek":0,"duration":217,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 28 19:43:36 vpmusica volumio[1267]: info: CoreCommandRouter::servicePushState Jun 28 19:43:36 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 0 Jun 28 19:43:36 vpmusica volumio[1267]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Hollywood","artist":"Lana Jurcevic","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","uri":"spotify:track:5j3SdyjQrT0myANQybhBWn","trackType":"spotify","seek":0,"duration":217,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 28 19:43:36 vpmusica volumio[1267]: verbose: CURRENT POSITION 0 Jun 28 19:43:36 vpmusica volumio[1267]: info: CoreStateMachine::syncState stateService play Jun 28 19:43:36 vpmusica volumio[1267]: info: CoreStateMachine::syncState currentStatus stop Jun 28 19:43:36 vpmusica volumio[1267]: SPOTIFY: PUSH STATE SPOTIFY Jun 28 19:43:36 vpmusica volumio[1267]: SPOTIFY: {"status":"play","service":"spop","title":"Hollywood","artist":"Lana Jurcevic","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","uri":"spotify:track:5j3SdyjQrT0myANQybhBWn","trackType":"spotify","seek":0,"duration":217,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 28 19:43:36 vpmusica volumio[1267]: info: CoreCommandRouter::servicePushState Jun 28 19:43:36 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 0 Jun 28 19:43:36 vpmusica volumio[1267]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Hollywood","artist":"Lana Jurcevic","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","uri":"spotify:track:5j3SdyjQrT0myANQybhBWn","trackType":"spotify","seek":0,"duration":217,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 28 19:43:36 vpmusica volumio[1267]: verbose: CURRENT POSITION 0 Jun 28 19:43:36 vpmusica volumio[1267]: info: CoreStateMachine::syncState stateService play Jun 28 19:43:36 vpmusica volumio[1267]: info: CoreStateMachine::syncState currentStatus play Jun 28 19:43:36 vpmusica volumio[1267]: info: Received an update from plugin. extracting info from payload Jun 28 19:43:36 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:43:36 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 0 Jun 28 19:43:36 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 19:43:36 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:43:36 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:43:36 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 0 Jun 28 19:43:36 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:43:36 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:43:36 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:43:37 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 28 19:43:37 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 28 19:43:37 vpmusica volumio[1267]: info: Discovery: Getting this device information Jun 28 19:43:37 vpmusica volumio[1267]: info: CoreCommandRouter::volumioGetState Jun 28 19:43:37 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 0 Jun 28 19:43:37 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 28 19:43:37 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 28 19:43:37 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 28 19:43:37 vpmusica volumio[1267]: info: Discovery: Getting this device information Jun 28 19:43:37 vpmusica volumio[1267]: info: CoreCommandRouter::volumioGetState Jun 28 19:43:37 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 0 Jun 28 19:43:37 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 28 19:43:44 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 28 19:43:44 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 28 19:43:44 vpmusica volumio[1267]: info: Discovery: Getting this device information Jun 28 19:43:44 vpmusica volumio[1267]: info: CoreCommandRouter::volumioGetState Jun 28 19:43:44 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 0 Jun 28 19:43:44 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 28 19:43:47 vpmusica go-librespot[1504]: time="2025-06-28T19:43:47+02:00" level=debug msg="fetched chunk 4/18, size: 524288" uri="spotify:track:5j3SdyjQrT0myANQybhBWn" Jun 28 19:43:49 vpmusica volumio[1267]: verbose: New Socket.io Connection to 192.168.100.51:3000 from 192.168.100.48 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 10 Jun 28 19:43:52 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 28 19:43:52 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 28 19:43:52 vpmusica volumio[1267]: info: Discovery: Getting this device information Jun 28 19:43:52 vpmusica volumio[1267]: info: CoreCommandRouter::volumioGetState Jun 28 19:43:52 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 0 Jun 28 19:43:52 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 28 19:43:58 vpmusica go-librespot[1504]: time="2025-06-28T19:43:58+02:00" level=debug msg="fetched chunk 5/18, size: 524288" uri="spotify:track:5j3SdyjQrT0myANQybhBWn" Jun 28 19:44:02 vpmusica volumio[1267]: verbose: New Socket.io Connection to 192.168.100.51:3000 from 192.168.100.48 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 11 Jun 28 19:44:05 vpmusica go-librespot[1504]: time="2025-06-28T19:44:05+02:00" level=trace msg="sent dealer ping" Jun 28 19:44:05 vpmusica go-librespot[1504]: time="2025-06-28T19:44:05+02:00" level=trace msg="received dealer pong" Jun 28 19:44:07 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 28 19:44:07 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 28 19:44:07 vpmusica volumio[1267]: info: Discovery: Getting this device information Jun 28 19:44:07 vpmusica volumio[1267]: info: CoreCommandRouter::volumioGetState Jun 28 19:44:07 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 0 Jun 28 19:44:07 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 28 19:44:10 vpmusica go-librespot[1504]: time="2025-06-28T19:44:10+02:00" level=debug msg="fetched chunk 6/18, size: 524288" uri="spotify:track:5j3SdyjQrT0myANQybhBWn" Jun 28 19:44:22 vpmusica go-librespot[1504]: time="2025-06-28T19:44:22+02:00" level=debug msg="fetched chunk 7/18, size: 524288" uri="spotify:track:5j3SdyjQrT0myANQybhBWn" Jun 28 19:44:22 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 28 19:44:22 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 28 19:44:22 vpmusica volumio[1267]: info: Discovery: Getting this device information Jun 28 19:44:22 vpmusica volumio[1267]: info: CoreCommandRouter::volumioGetState Jun 28 19:44:22 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 0 Jun 28 19:44:22 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 28 19:44:29 vpmusica systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jun 28 19:44:29 vpmusica dbus-daemon[689]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.440' (uid=0 pid=1243 comm="timedatectl show --property=NTPSynchronized --valu") Jun 28 19:44:29 vpmusica systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jun 28 19:44:29 vpmusica dbus-daemon[689]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 28 19:44:29 vpmusica systemd[1]: Started systemd-timedated.service - Time & Date Service. Jun 28 19:44:29 vpmusica setdatetime-helper.sh[1242]: Time is already synchronized. Jun 28 19:44:29 vpmusica systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jun 28 19:44:29 vpmusica systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jun 28 19:44:33 vpmusica volumio[1267]: verbose: New Socket.io Connection to 192.168.100.51 from 192.168.100.37 UA: Mozilla/5.0 (Linux; Android 15; SM-S908B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/137.0.7151.115 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Jun 28 19:44:33 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 28 19:44:33 vpmusica volumio[1267]: info: CoreCommandRouter::volumioGetVisibleSources Jun 28 19:44:33 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 19:44:33 vpmusica volumio[1267]: info: CoreCommandRouter::volumioGetState Jun 28 19:44:33 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 0 Jun 28 19:44:33 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 28 19:44:33 vpmusica volumio[1267]: info: CoreCommandRouter::volumioGetQueue Jun 28 19:44:33 vpmusica volumio[1267]: info: CoreStateMachine::getQueue Jun 28 19:44:33 vpmusica volumio[1267]: info: CorePlayQueue::getQueue Jun 28 19:44:33 vpmusica volumio[1267]: info: Listing playlists Jun 28 19:44:33 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 28 19:44:33 vpmusica volumio[1267]: info: Received Get System Info Jun 28 19:44:33 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 28 19:44:33 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 28 19:44:33 vpmusica volumio[1267]: info: Discovery: Getting this device information Jun 28 19:44:33 vpmusica volumio[1267]: info: CoreCommandRouter::volumioGetState Jun 28 19:44:33 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 0 Jun 28 19:44:33 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 28 19:44:33 vpmusica volumio[1267]: info: CoreCommandRouter::volumioGetState Jun 28 19:44:33 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 0 Jun 28 19:44:33 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 28 19:44:34 vpmusica go-librespot[1504]: time="2025-06-28T19:44:34+02:00" level=debug msg="fetched chunk 8/18, size: 524288" uri="spotify:track:5j3SdyjQrT0myANQybhBWn" Jun 28 19:44:35 vpmusica go-librespot[1504]: time="2025-06-28T19:44:35+02:00" level=trace msg="sent dealer ping" Jun 28 19:44:35 vpmusica go-librespot[1504]: time="2025-06-28T19:44:35+02:00" level=trace msg="received dealer pong" Jun 28 19:44:37 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 28 19:44:37 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 28 19:44:37 vpmusica volumio[1267]: info: Discovery: Getting this device information Jun 28 19:44:37 vpmusica volumio[1267]: info: CoreCommandRouter::volumioGetState Jun 28 19:44:37 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 0 Jun 28 19:44:37 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 28 19:44:38 vpmusica volumio[1267]: info: CoreCommandRouter::volumioNext Jun 28 19:44:38 vpmusica volumio[1267]: info: CoreStateMachine::next Jun 28 19:44:38 vpmusica volumio[1267]: info: CoreStateMachine::stop Jun 28 19:44:38 vpmusica volumio[1267]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 28 19:44:38 vpmusica volumio[1267]: info: CoreStateMachine::stPlaybackTimer Jun 28 19:44:38 vpmusica volumio[1267]: info: CoreStateMachine::updateTrackBlock Jun 28 19:44:38 vpmusica volumio[1267]: info: CorePlayQueue::getTrackBlock Jun 28 19:44:38 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:44:38 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 0 Jun 28 19:44:38 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 19:44:38 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:44:38 vpmusica volumio[1267]: info: CoreStateMachine::serviceStop Jun 28 19:44:38 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 0 Jun 28 19:44:38 vpmusica volumio[1267]: info: CoreCommandRouter::serviceStop Jun 28 19:44:38 vpmusica volumio[1267]: info: Spotify Stop Jun 28 19:44:38 vpmusica volumio[1267]: SPOTIFY: SPOTIFY STOP Jun 28 19:44:38 vpmusica volumio[1267]: SPOTIFY: {"status":"play","position":0,"title":"Hollywood","artist":"Lana Jurcevic","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","uri":"spotify:track:5j3SdyjQrT0myANQybhBWn","trackType":"spotify","codec":"ogg","seek":0,"duration":217,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":false,"repeat":true,"repeatSingle":false,"consume":false,"volume":83,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Jun 28 19:44:38 vpmusica volumio[1267]: info: Sending Spotify command to local API: /player/pause Jun 28 19:44:38 vpmusica volumio[1267]: info: CoreStateMachine::play index undefined Jun 28 19:44:38 vpmusica volumio[1267]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 28 19:44:38 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 1 Jun 28 19:44:38 vpmusica volumio[1267]: info: CoreStateMachine::startPlaybackTimer Jun 28 19:44:38 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 1 Jun 28 19:44:38 vpmusica volumio[1267]: info: [1751132678341] ControllerSpotify::clearAddPlayTrack Jun 28 19:44:38 vpmusica volumio[1267]: info: Sending Spotify command with payload to local API: /player/play Jun 28 19:44:38 vpmusica volumio[1267]: info: CoreStateMachine::updateTrackBlock Jun 28 19:44:38 vpmusica volumio[1267]: info: CorePlayQueue::getTrackBlock Jun 28 19:44:38 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:44:38 vpmusica go-librespot[1504]: time="2025-06-28T19:44:38+02:00" level=debug msg="pause track at 62147ms" Jun 28 19:44:38 vpmusica go-librespot[1504]: time="2025-06-28T19:44:38+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 28 19:44:38 vpmusica go-librespot[1504]: time="2025-06-28T19:44:38+02:00" level=debug msg="resolved context of track" uri="spotify:track:5JYds8Xn7inmXSnvcuFno3" Jun 28 19:44:38 vpmusica go-librespot[1504]: time="2025-06-28T19:44:38+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:5JYds8Xn7inmXSnvcuFno3" Jun 28 19:44:38 vpmusica go-librespot[1504]: time="2025-06-28T19:44:38+02:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:5JYds8Xn7inmXSnvcuFno3" Jun 28 19:44:38 vpmusica go-librespot[1504]: time="2025-06-28T19:44:38+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 28 19:44:38 vpmusica go-librespot[1504]: time="2025-06-28T19:44:38+02:00" level=trace msg="emitting websocket event: will_play" Jun 28 19:44:38 vpmusica volumio[1267]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5JYds8Xn7inmXSnvcuFno3","play_origin":"go-librespot"}} Jun 28 19:44:38 vpmusica go-librespot[1504]: time="2025-06-28T19:44:38+02:00" level=debug msg="selected format OGG_VORBIS_320 (620a212a50391437384ba01a8df1d4f95d90ac01)" uri="spotify:track:5JYds8Xn7inmXSnvcuFno3" Jun 28 19:44:38 vpmusica go-librespot[1504]: time="2025-06-28T19:44:38+02:00" level=debug msg="requested aes key for file 620a212a50391437384ba01a8df1d4f95d90ac01, gid: 5JYds8Xn7inmXSnvcuFno3" Jun 28 19:44:39 vpmusica go-librespot[1504]: time="2025-06-28T19:44:39+02:00" level=debug msg="fetched first chunk of 20, total size is 9966571 bytes" uri="spotify:track:5JYds8Xn7inmXSnvcuFno3" Jun 28 19:44:39 vpmusica go-librespot[1504]: time="2025-06-28T19:44:39+02:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:5JYds8Xn7inmXSnvcuFno3" Jun 28 19:44:39 vpmusica go-librespot[1504]: time="2025-06-28T19:44:39+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames" Jun 28 19:44:39 vpmusica go-librespot[1504]: time="2025-06-28T19:44:39+02:00" level=info msg="loaded track \"Kaktus\" (paused: false, position: 1ms, duration: 231866ms, prefetched: false)" uri="spotify:track:5JYds8Xn7inmXSnvcuFno3" Jun 28 19:44:39 vpmusica go-librespot[1504]: time="2025-06-28T19:44:39+02:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:5JYds8Xn7inmXSnvcuFno3" Jun 28 19:44:39 vpmusica go-librespot[1504]: time="2025-06-28T19:44:39+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 28 19:44:39 vpmusica go-librespot[1504]: time="2025-06-28T19:44:39+02:00" level=trace msg="scheduling prefetch in 202s" Jun 28 19:44:39 vpmusica go-librespot[1504]: time="2025-06-28T19:44:39+02:00" level=trace msg="emitting websocket event: metadata" Jun 28 19:44:39 vpmusica volumio[1267]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5JYds8Xn7inmXSnvcuFno3","name":"Kaktus","artist_names":["Lidija Bačić"],"album_name":"Zabavni Mix Hitovi","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","position":1,"duration":231866,"release_date":"year:2015 month:4 day:17","track_number":2,"disc_number":1}} Jun 28 19:44:39 vpmusica go-librespot[1504]: time="2025-06-28T19:44:39+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 28 19:44:39 vpmusica go-librespot[1504]: time="2025-06-28T19:44:39+02:00" level=trace msg="emitting websocket event: paused" Jun 28 19:44:39 vpmusica volumio[1267]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5JYds8Xn7inmXSnvcuFno3","play_origin":"go-librespot"}} Jun 28 19:44:39 vpmusica volumio[1267]: SPOTIFY: PUSH STATE SPOTIFY Jun 28 19:44:39 vpmusica volumio[1267]: SPOTIFY: {"status":"pause","service":"spop","title":"Kaktus","artist":"Lidija Bačić","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","uri":"spotify:track:5JYds8Xn7inmXSnvcuFno3","trackType":"spotify","seek":1,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 28 19:44:39 vpmusica volumio[1267]: info: CoreCommandRouter::servicePushState Jun 28 19:44:39 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 1 Jun 28 19:44:39 vpmusica volumio[1267]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Kaktus","artist":"Lidija Bačić","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","uri":"spotify:track:5JYds8Xn7inmXSnvcuFno3","trackType":"spotify","seek":1,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 28 19:44:39 vpmusica volumio[1267]: verbose: CURRENT POSITION 1 Jun 28 19:44:39 vpmusica volumio[1267]: info: CoreStateMachine::syncState stateService pause Jun 28 19:44:39 vpmusica volumio[1267]: info: CoreStateMachine::syncState currentStatus stop Jun 28 19:44:39 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:44:39 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 1 Jun 28 19:44:39 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 19:44:39 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:44:39 vpmusica go-librespot[1504]: time="2025-06-28T19:44:39+02:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:5JYds8Xn7inmXSnvcuFno3" Jun 28 19:44:39 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:44:39 vpmusica go-librespot[1504]: time="2025-06-28T19:44:39+02:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:5JYds8Xn7inmXSnvcuFno3" Jun 28 19:44:39 vpmusica go-librespot[1504]: time="2025-06-28T19:44:39+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 28 19:44:39 vpmusica go-librespot[1504]: time="2025-06-28T19:44:39+02:00" level=trace msg="emitting websocket event: playing" Jun 28 19:44:39 vpmusica volumio[1267]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5JYds8Xn7inmXSnvcuFno3","play_origin":"go-librespot"}} Jun 28 19:44:39 vpmusica volumio[1267]: SPOTIFY: PUSH STATE SPOTIFY Jun 28 19:44:39 vpmusica volumio[1267]: SPOTIFY: {"status":"play","service":"spop","title":"Kaktus","artist":"Lidija Bačić","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","uri":"spotify:track:5JYds8Xn7inmXSnvcuFno3","trackType":"spotify","seek":1,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 28 19:44:39 vpmusica volumio[1267]: info: CoreCommandRouter::servicePushState Jun 28 19:44:39 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 1 Jun 28 19:44:39 vpmusica volumio[1267]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Kaktus","artist":"Lidija Bačić","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","uri":"spotify:track:5JYds8Xn7inmXSnvcuFno3","trackType":"spotify","seek":1,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 28 19:44:39 vpmusica volumio[1267]: verbose: CURRENT POSITION 1 Jun 28 19:44:39 vpmusica volumio[1267]: info: CoreStateMachine::syncState stateService play Jun 28 19:44:39 vpmusica volumio[1267]: info: CoreStateMachine::syncState currentStatus stop Jun 28 19:44:39 vpmusica volumio[1267]: SPOTIFY: PUSH STATE SPOTIFY Jun 28 19:44:39 vpmusica volumio[1267]: SPOTIFY: {"status":"play","service":"spop","title":"Kaktus","artist":"Lidija Bačić","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","uri":"spotify:track:5JYds8Xn7inmXSnvcuFno3","trackType":"spotify","seek":1,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 28 19:44:39 vpmusica volumio[1267]: info: CoreCommandRouter::servicePushState Jun 28 19:44:39 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 1 Jun 28 19:44:39 vpmusica volumio[1267]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Kaktus","artist":"Lidija Bačić","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","uri":"spotify:track:5JYds8Xn7inmXSnvcuFno3","trackType":"spotify","seek":1,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 28 19:44:39 vpmusica volumio[1267]: verbose: CURRENT POSITION 1 Jun 28 19:44:39 vpmusica volumio[1267]: info: CoreStateMachine::syncState stateService play Jun 28 19:44:39 vpmusica volumio[1267]: info: CoreStateMachine::syncState currentStatus play Jun 28 19:44:39 vpmusica volumio[1267]: info: Received an update from plugin. extracting info from payload Jun 28 19:44:39 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:44:39 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 1 Jun 28 19:44:39 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 19:44:39 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:44:39 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:44:39 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 1 Jun 28 19:44:39 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:44:40 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:44:40 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:44:41 vpmusica volumio[1267]: info: CoreCommandRouter::volumioNext Jun 28 19:44:41 vpmusica volumio[1267]: info: CoreStateMachine::next Jun 28 19:44:41 vpmusica volumio[1267]: info: CoreStateMachine::stop Jun 28 19:44:41 vpmusica volumio[1267]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 28 19:44:41 vpmusica volumio[1267]: info: CoreStateMachine::stPlaybackTimer Jun 28 19:44:41 vpmusica volumio[1267]: info: CoreStateMachine::updateTrackBlock Jun 28 19:44:41 vpmusica volumio[1267]: info: CorePlayQueue::getTrackBlock Jun 28 19:44:41 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:44:41 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 1 Jun 28 19:44:41 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 19:44:41 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:44:41 vpmusica volumio[1267]: info: CoreStateMachine::serviceStop Jun 28 19:44:41 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 1 Jun 28 19:44:41 vpmusica volumio[1267]: info: CoreCommandRouter::serviceStop Jun 28 19:44:41 vpmusica volumio[1267]: info: Spotify Stop Jun 28 19:44:41 vpmusica volumio[1267]: SPOTIFY: SPOTIFY STOP Jun 28 19:44:41 vpmusica volumio[1267]: SPOTIFY: {"status":"play","position":1,"title":"Kaktus","artist":"Lidija Bačić","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","uri":"spotify:track:5JYds8Xn7inmXSnvcuFno3","trackType":"spotify","codec":"ogg","seek":1,"duration":231,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":false,"repeat":true,"repeatSingle":false,"consume":false,"volume":83,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Jun 28 19:44:41 vpmusica volumio[1267]: info: Sending Spotify command to local API: /player/pause Jun 28 19:44:41 vpmusica volumio[1267]: info: CoreStateMachine::play index undefined Jun 28 19:44:41 vpmusica volumio[1267]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 28 19:44:41 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 2 Jun 28 19:44:41 vpmusica volumio[1267]: info: CoreStateMachine::startPlaybackTimer Jun 28 19:44:41 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 2 Jun 28 19:44:41 vpmusica volumio[1267]: info: [1751132681067] ControllerSpotify::clearAddPlayTrack Jun 28 19:44:41 vpmusica volumio[1267]: info: Sending Spotify command with payload to local API: /player/play Jun 28 19:44:41 vpmusica volumio[1267]: info: CoreStateMachine::updateTrackBlock Jun 28 19:44:41 vpmusica volumio[1267]: info: CorePlayQueue::getTrackBlock Jun 28 19:44:41 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:44:41 vpmusica go-librespot[1504]: time="2025-06-28T19:44:41+02:00" level=debug msg="pause track at 1609ms" Jun 28 19:44:41 vpmusica go-librespot[1504]: time="2025-06-28T19:44:41+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 28 19:44:41 vpmusica go-librespot[1504]: time="2025-06-28T19:44:41+02:00" level=debug msg="resolved context of track" uri="spotify:track:4obmf0WqbLqFPEUvh45qI6" Jun 28 19:44:41 vpmusica go-librespot[1504]: time="2025-06-28T19:44:41+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:4obmf0WqbLqFPEUvh45qI6" Jun 28 19:44:41 vpmusica go-librespot[1504]: time="2025-06-28T19:44:41+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:4obmf0WqbLqFPEUvh45qI6" Jun 28 19:44:41 vpmusica go-librespot[1504]: time="2025-06-28T19:44:41+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 28 19:44:41 vpmusica go-librespot[1504]: time="2025-06-28T19:44:41+02:00" level=trace msg="emitting websocket event: will_play" Jun 28 19:44:41 vpmusica volumio[1267]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4obmf0WqbLqFPEUvh45qI6","play_origin":"go-librespot"}} Jun 28 19:44:41 vpmusica go-librespot[1504]: time="2025-06-28T19:44:41+02:00" level=debug msg="selected format OGG_VORBIS_320 (74599ff45b7851a868fc292c0a4d113ac83439c4)" uri="spotify:track:4obmf0WqbLqFPEUvh45qI6" Jun 28 19:44:41 vpmusica go-librespot[1504]: time="2025-06-28T19:44:41+02:00" level=debug msg="requested aes key for file 74599ff45b7851a868fc292c0a4d113ac83439c4, gid: 4obmf0WqbLqFPEUvh45qI6" Jun 28 19:44:42 vpmusica go-librespot[1504]: time="2025-06-28T19:44:42+02:00" level=debug msg="fetched first chunk of 16, total size is 7920753 bytes" uri="spotify:track:4obmf0WqbLqFPEUvh45qI6" Jun 28 19:44:42 vpmusica go-librespot[1504]: time="2025-06-28T19:44:42+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames" Jun 28 19:44:42 vpmusica go-librespot[1504]: time="2025-06-28T19:44:42+02:00" level=info msg="loaded track \"Zavela Me Ana\" (paused: false, position: 0ms, duration: 182333ms, prefetched: false)" uri="spotify:track:4obmf0WqbLqFPEUvh45qI6" Jun 28 19:44:42 vpmusica go-librespot[1504]: time="2025-06-28T19:44:42+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 28 19:44:42 vpmusica go-librespot[1504]: time="2025-06-28T19:44:42+02:00" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:4obmf0WqbLqFPEUvh45qI6" Jun 28 19:44:42 vpmusica go-librespot[1504]: time="2025-06-28T19:44:42+02:00" level=trace msg="scheduling prefetch in 152s" Jun 28 19:44:42 vpmusica go-librespot[1504]: time="2025-06-28T19:44:42+02:00" level=trace msg="emitting websocket event: metadata" Jun 28 19:44:42 vpmusica volumio[1267]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4obmf0WqbLqFPEUvh45qI6","name":"Zavela Me Ana","artist_names":["Ts Mejaši"],"album_name":"Zabavni Mix Hitovi","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","position":0,"duration":182333,"release_date":"year:2015 month:4 day:17","track_number":3,"disc_number":1}} Jun 28 19:44:42 vpmusica go-librespot[1504]: time="2025-06-28T19:44:42+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 28 19:44:42 vpmusica go-librespot[1504]: time="2025-06-28T19:44:42+02:00" level=trace msg="emitting websocket event: paused" Jun 28 19:44:42 vpmusica volumio[1267]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:4obmf0WqbLqFPEUvh45qI6","play_origin":"go-librespot"}} Jun 28 19:44:42 vpmusica volumio[1267]: SPOTIFY: PUSH STATE SPOTIFY Jun 28 19:44:42 vpmusica volumio[1267]: SPOTIFY: {"status":"pause","service":"spop","title":"Zavela Me Ana","artist":"Ts Mejaši","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","uri":"spotify:track:4obmf0WqbLqFPEUvh45qI6","trackType":"spotify","seek":0,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 28 19:44:42 vpmusica volumio[1267]: info: CoreCommandRouter::servicePushState Jun 28 19:44:42 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 2 Jun 28 19:44:42 vpmusica volumio[1267]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Zavela Me Ana","artist":"Ts Mejaši","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","uri":"spotify:track:4obmf0WqbLqFPEUvh45qI6","trackType":"spotify","seek":0,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 28 19:44:42 vpmusica volumio[1267]: verbose: CURRENT POSITION 2 Jun 28 19:44:42 vpmusica volumio[1267]: info: CoreStateMachine::syncState stateService pause Jun 28 19:44:42 vpmusica volumio[1267]: info: CoreStateMachine::syncState currentStatus stop Jun 28 19:44:42 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:44:42 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 2 Jun 28 19:44:42 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 19:44:42 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:44:42 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:44:42 vpmusica go-librespot[1504]: time="2025-06-28T19:44:42+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 28 19:44:42 vpmusica go-librespot[1504]: time="2025-06-28T19:44:42+02:00" level=trace msg="emitting websocket event: playing" Jun 28 19:44:42 vpmusica volumio[1267]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4obmf0WqbLqFPEUvh45qI6","play_origin":"go-librespot"}} Jun 28 19:44:42 vpmusica volumio[1267]: SPOTIFY: PUSH STATE SPOTIFY Jun 28 19:44:42 vpmusica volumio[1267]: SPOTIFY: {"status":"play","service":"spop","title":"Zavela Me Ana","artist":"Ts Mejaši","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","uri":"spotify:track:4obmf0WqbLqFPEUvh45qI6","trackType":"spotify","seek":0,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 28 19:44:42 vpmusica volumio[1267]: info: CoreCommandRouter::servicePushState Jun 28 19:44:42 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 2 Jun 28 19:44:42 vpmusica volumio[1267]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Zavela Me Ana","artist":"Ts Mejaši","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","uri":"spotify:track:4obmf0WqbLqFPEUvh45qI6","trackType":"spotify","seek":0,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 28 19:44:42 vpmusica volumio[1267]: verbose: CURRENT POSITION 2 Jun 28 19:44:42 vpmusica volumio[1267]: info: CoreStateMachine::syncState stateService play Jun 28 19:44:42 vpmusica volumio[1267]: info: CoreStateMachine::syncState currentStatus stop Jun 28 19:44:42 vpmusica go-librespot[1504]: time="2025-06-28T19:44:42+02:00" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:4obmf0WqbLqFPEUvh45qI6" Jun 28 19:44:42 vpmusica go-librespot[1504]: time="2025-06-28T19:44:42+02:00" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:4obmf0WqbLqFPEUvh45qI6" Jun 28 19:44:42 vpmusica volumio[1267]: SPOTIFY: PUSH STATE SPOTIFY Jun 28 19:44:42 vpmusica volumio[1267]: SPOTIFY: {"status":"play","service":"spop","title":"Zavela Me Ana","artist":"Ts Mejaši","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","uri":"spotify:track:4obmf0WqbLqFPEUvh45qI6","trackType":"spotify","seek":0,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 28 19:44:42 vpmusica volumio[1267]: info: CoreCommandRouter::servicePushState Jun 28 19:44:42 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 2 Jun 28 19:44:42 vpmusica volumio[1267]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Zavela Me Ana","artist":"Ts Mejaši","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","uri":"spotify:track:4obmf0WqbLqFPEUvh45qI6","trackType":"spotify","seek":0,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 28 19:44:42 vpmusica volumio[1267]: verbose: CURRENT POSITION 2 Jun 28 19:44:42 vpmusica volumio[1267]: info: CoreStateMachine::syncState stateService play Jun 28 19:44:42 vpmusica volumio[1267]: info: CoreStateMachine::syncState currentStatus play Jun 28 19:44:42 vpmusica volumio[1267]: info: Received an update from plugin. extracting info from payload Jun 28 19:44:42 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:44:42 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 2 Jun 28 19:44:42 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 19:44:42 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:44:42 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:44:42 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 2 Jun 28 19:44:42 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:44:42 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:44:42 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:44:43 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPause Jun 28 19:44:43 vpmusica volumio[1267]: info: CoreStateMachine::pause Jun 28 19:44:43 vpmusica volumio[1267]: info: CoreStateMachine::stPlaybackTimer Jun 28 19:44:43 vpmusica volumio[1267]: info: CoreStateMachine::servicePause Jun 28 19:44:43 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 2 Jun 28 19:44:43 vpmusica volumio[1267]: info: CoreCommandRouter::servicePause Jun 28 19:44:43 vpmusica volumio[1267]: info: Spotify Received pause Jun 28 19:44:43 vpmusica volumio[1267]: SPOTIFY: SPOTIFY PAUSE Jun 28 19:44:43 vpmusica volumio[1267]: SPOTIFY: {"status":"play","position":2,"title":"Zavela Me Ana","artist":"Ts Mejaši","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d0000b27379e9af3cca40b5a4f3763eb5","uri":"spotify:track:4obmf0WqbLqFPEUvh45qI6","trackType":"spotify","codec":"ogg","seek":0,"duration":182,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":false,"repeat":true,"repeatSingle":false,"consume":false,"volume":83,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Jun 28 19:44:43 vpmusica volumio[1267]: info: Sending Spotify command to local API: /player/pause Jun 28 19:44:43 vpmusica go-librespot[1504]: time="2025-06-28T19:44:43+02:00" level=debug msg="pause track at 1292ms" Jun 28 19:44:43 vpmusica go-librespot[1504]: time="2025-06-28T19:44:43+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 28 19:44:43 vpmusica go-librespot[1504]: time="2025-06-28T19:44:43+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 28 19:44:43 vpmusica go-librespot[1504]: time="2025-06-28T19:44:43+02:00" level=trace msg="emitting websocket event: paused" Jun 28 19:44:43 vpmusica volumio[1267]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:4obmf0WqbLqFPEUvh45qI6","play_origin":"go-librespot"}} Jun 28 19:44:43 vpmusica volumio[1267]: SPOTIFY: PUSH STATE SPOTIFY Jun 28 19:44:43 vpmusica volumio[1267]: SPOTIFY: {"status":"pause","service":"spop","title":"Zavela Me Ana","artist":"Ts Mejaši","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","uri":"spotify:track:4obmf0WqbLqFPEUvh45qI6","trackType":"spotify","seek":1000,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 28 19:44:43 vpmusica volumio[1267]: info: CoreCommandRouter::servicePushState Jun 28 19:44:43 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 2 Jun 28 19:44:43 vpmusica volumio[1267]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Zavela Me Ana","artist":"Ts Mejaši","album":"Zabavni Mix Hitovi","albumart":"https://i.scdn.co/image/ab67616d00001e0279e9af3cca40b5a4f3763eb5","uri":"spotify:track:4obmf0WqbLqFPEUvh45qI6","trackType":"spotify","seek":1000,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 28 19:44:43 vpmusica volumio[1267]: verbose: CURRENT POSITION 2 Jun 28 19:44:43 vpmusica volumio[1267]: info: CoreStateMachine::syncState stateService pause Jun 28 19:44:43 vpmusica volumio[1267]: info: CoreStateMachine::syncState currentStatus pause Jun 28 19:44:43 vpmusica volumio[1267]: info: CoreStateMachine::pushState Jun 28 19:44:43 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 2 Jun 28 19:44:43 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 19:44:43 vpmusica volumio[1267]: info: CoreCommandRouter::volumioPushState Jun 28 19:44:43 vpmusica volumio[1267]: info: CoreStateMachine::stPlaybackTimer Jun 28 19:44:43 vpmusica volumio[1267]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Jun 28 19:44:52 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 28 19:44:52 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 28 19:44:52 vpmusica volumio[1267]: info: Discovery: Getting this device information Jun 28 19:44:52 vpmusica volumio[1267]: info: CoreCommandRouter::volumioGetState Jun 28 19:44:52 vpmusica volumio[1267]: info: CorePlayQueue::getTrack 2 Jun 28 19:44:52 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 28 19:44:54 vpmusica volumio[1267]: Searching all installed plugins Jun 28 19:44:54 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 19:44:54 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: , search Jun 28 19:44:54 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jun 28 19:44:54 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Jun 28 19:44:54 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Jun 28 19:44:54 vpmusica volumio[1267]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Jun 28 19:44:54 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: webradio , search Jun 28 19:44:54 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search Jun 28 19:44:54 vpmusica volumio[1267]: info: CoreCommandRouter::executeOnPlugin: spop , search Jun 28 19:44:54 vpmusica volumio[1267]: Use XMLElement.setAttribute instead Jun 28 19:44:54 vpmusica volumio[1267]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 28 19:44:54 vpmusica volumio[1267]: TypeError: children[i].attr(...).value is not a function Jun 28 19:44:54 vpmusica volumio[1267]: at /volumio/app/plugins/music_service/webradio/index.js:956:46 Jun 28 19:44:54 vpmusica volumio[1267]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Jun 28 19:44:54 vpmusica volumio[1267]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 28 19:44:54 vpmusica sudo[1317]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-06-28 19:43' Jun 28 19:44:54 vpmusica sudo[1317]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="e04947e3c75ec6c2c2acf1309457074dbcd9b4da" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon May 26 21:14:52 UTC 2025" VOLUMIO_VERSION="4.001" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="6ce95a84f661af5ae06957ac4da91414"