-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Tue 2024-07-16 10:41:30 CEST. -- Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3ydfhgIZIc2j39NLIhpJpq","service":"spop","name":"Fuck You","artist":"CeeLo Green","album":"The Lady Killer (Deluxe)","type":"song","duration":223,"albumart":"https://i.scdn.co/image/ab67616d0000b2731c44d79c994c1a26aa387617","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:58rFvJfLuVEFel86hkoYez","service":"spop","name":"No Mercy","artist":"Racoon","album":"Liverpool Rain","type":"song","duration":167,"albumart":"https://i.scdn.co/image/ab67616d0000b2738f446d8d9df6a85090a196b1","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:65OXGbKBQ8gUyJvUd0jNpf","service":"spop","name":"Boom, Boom, Boom, Boom!!","artist":"Vengaboys","album":"Greatest Hits!","type":"song","duration":202,"albumart":"https://i.scdn.co/image/ab67616d0000b27354be522e5e1814efa54a31b3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7K26jwuBYEodBYQCg4OymD","service":"spop","name":"Ons Moeder Zeej Nog","artist":"Jan Biggel","album":"Ons Moeder Zeej Nog","type":"song","duration":222,"albumart":"https://i.scdn.co/image/ab67616d0000b273ee36a78a4e34bf74566e7eb3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6trzHhvr6xqYJkNnbWwXz2","service":"spop","name":"We're Going To Ibiza!","artist":"Vengaboys","album":"The Party Album!","type":"song","duration":217,"albumart":"https://i.scdn.co/image/ab67616d0000b27350fcab12b2e2e0ee0019ac53","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1jnUXW29r0JgYRcQmC3gIp","service":"spop","name":"Het Is Een Nacht... (Levensecht)","artist":"Guus Meeuwis","album":"Verbazing","type":"song","duration":225,"albumart":"https://i.scdn.co/image/ab67616d0000b273856a611ca5e21412716469fa","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0gq4UgDPGFdqpsWshU7dmv","service":"spop","name":"Vanavond (Uit M'n Bol)","artist":"Kris Kross Amsterdam","album":"Vanavond (Uit M'n Bol)","type":"song","duration":166,"albumart":"https://i.scdn.co/image/ab67616d0000b2737f53900c7289196d3045627f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0jIcyUmf5aANj4ZAaHTizi","service":"spop","name":"Als Je Lacht","artist":"Jan Smit","album":"Stilte In De Storm","type":"song","duration":234,"albumart":"https://i.scdn.co/image/ab67616d0000b2739eada168548571df3bd0d680","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7sMx7mu0VxhEcrfATmLok6","service":"spop","name":"Leef Nu Het Kan","artist":"Jan Smit","album":"Leef (Deluxe Edition)","type":"song","duration":181,"albumart":"https://i.scdn.co/image/ab67616d0000b273d3264e93ac928b4571845f74","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1Mys1gf9SkMBAVGGxpkJ7d","service":"spop","name":"Reality","artist":"Lost Frequencies","album":"Less Is More","type":"song","duration":159,"albumart":"https://i.scdn.co/image/ab67616d0000b2735885e21feca8ad43b2f3f573","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3c28vYkrzU9nVqvJfbaSiu","service":"spop","name":"Amalia","artist":"Wesly Bronkhorst","album":"Amalia","type":"song","duration":157,"albumart":"https://i.scdn.co/image/ab67616d0000b27337a75c3ce8cf501e0d54e044","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1q9l6c8bAzqWcvO3DM6FsR","service":"spop","name":"I Don't Feel Like Dancin'","artist":"Scissor Sisters","album":"Ta Dah","type":"song","duration":288,"albumart":"https://i.scdn.co/image/ab67616d0000b27381625c8c1368106d3ac464ed","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0IykHENBld5IDitOTBRRDW","service":"spop","name":"Just A Flirt","artist":"Miss Montreal","album":"Miss Montreal","type":"song","duration":207,"albumart":"https://i.scdn.co/image/ab67616d0000b273f37b5b21c5559a0dd605ff9d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1jDJFeK9x3OZboIAHsY9k2","service":"spop","name":"I'm Still Standing","artist":"Elton John","album":"Too Low For Zero","type":"song","duration":183,"albumart":"https://i.scdn.co/image/ab67616d0000b273eb11e2abccdca41f39ad3b89","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5rgTXjUWeNTEJh578O7GCc","service":"spop","name":"'t Dondert En 't Bliksemt","artist":"Guus Meeuwis","album":"Schilderij","type":"song","duration":192,"albumart":"https://i.scdn.co/image/ab67616d0000b27352076b7ab169033de0157751","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioPushQueue Jul 16 10:40:00 foxsoftradio volumio[939]: info: CorePlayQueue::saveQueue Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreStateMachine::updateTrackBlock Jul 16 10:40:00 foxsoftradio volumio[939]: info: CorePlayQueue::getTrackBlock Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioPlay Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreStateMachine::play index 1 Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreStateMachine::stop Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreStateMachine::play index undefined Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 16 10:40:00 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreStateMachine::startPlaybackTimer Jul 16 10:40:00 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:00 foxsoftradio volumio[939]: info: [1721119200414] ControllerSpotify::clearAddPlayTrack Jul 16 10:40:00 foxsoftradio volumio[939]: info: Sending Spotify command with payload to local API: /player/play Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioGetState Jul 16 10:40:00 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:00 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:00+02:00" level=debug msg="resolved context spotify:track:0vrKBjEBQAVn3sdhIXmpHE" Jul 16 10:40:00 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:00+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" Jul 16 10:40:00 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:00+02:00" level=debug msg="loading track spotify:track:0vrKBjEBQAVn3sdhIXmpHE (paused: false, position: 0ms)" Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:37oajE6ezfuQ1tjyWlF0UW","service":"spop","name":"Turk Uit De Kroeg","artist":"Ammar","album":"Turk Uit De Kroeg","type":"song","duration":192,"albumart":"https://i.scdn.co/image/ab67616d0000b273d04fcb1a5b6b8e2d9a06ccad","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:00+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 16 10:40:00 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:00+02:00" level=trace msg="emitting websocket event: will_play" Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6Z9x2fuHPLjOLbfSiTKxUQ","service":"spop","name":"Uit Elkaar","artist":"Yes-R","album":"Het Beste Van Yes-R","type":"song","duration":197,"albumart":"https://i.scdn.co/image/ab67616d0000b2730b28c1119b870194b8fa1abb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0vrKBjEBQAVn3sdhIXmpHE","play_origin":"go-librespot"}} Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3ydfhgIZIc2j39NLIhpJpq","service":"spop","name":"Fuck You","artist":"CeeLo Green","album":"The Lady Killer (Deluxe)","type":"song","duration":223,"albumart":"https://i.scdn.co/image/ab67616d0000b2731c44d79c994c1a26aa387617","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:65OXGbKBQ8gUyJvUd0jNpf","service":"spop","name":"Boom, Boom, Boom, Boom!!","artist":"Vengaboys","album":"Greatest Hits!","type":"song","duration":202,"albumart":"https://i.scdn.co/image/ab67616d0000b27354be522e5e1814efa54a31b3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0LbT0dDbSXAus5hhLfuTVu","service":"spop","name":"Alles Komt Goed","artist":"Jaap Reesema","album":"Alles Komt Goed","type":"song","duration":184,"albumart":"https://i.scdn.co/image/ab67616d0000b2732bff1bcf30bc72fa437765b5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6trzHhvr6xqYJkNnbWwXz2","service":"spop","name":"We're Going To Ibiza!","artist":"Vengaboys","album":"The Party Album!","type":"song","duration":217,"albumart":"https://i.scdn.co/image/ab67616d0000b27350fcab12b2e2e0ee0019ac53","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:00+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:0vrKBjEBQAVn3sdhIXmpHE" Jul 16 10:40:00 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:00+02:00" level=debug msg="requested aes key for file 754f013bd16ae72a92d987d8506833bf7cb77f8a, gid: 0vrKBjEBQAVn3sdhIXmpHE" Jul 16 10:40:00 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:00+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Jul 16 10:40:00 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:00+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:58rFvJfLuVEFel86hkoYez","service":"spop","name":"No Mercy","artist":"Racoon","album":"Liverpool Rain","type":"song","duration":167,"albumart":"https://i.scdn.co/image/ab67616d0000b2738f446d8d9df6a85090a196b1","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7K26jwuBYEodBYQCg4OymD","service":"spop","name":"Ons Moeder Zeej Nog","artist":"Jan Biggel","album":"Ons Moeder Zeej Nog","type":"song","duration":222,"albumart":"https://i.scdn.co/image/ab67616d0000b273ee36a78a4e34bf74566e7eb3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5rgTXjUWeNTEJh578O7GCc","service":"spop","name":"'t Dondert En 't Bliksemt","artist":"Guus Meeuwis","album":"Schilderij","type":"song","duration":192,"albumart":"https://i.scdn.co/image/ab67616d0000b27352076b7ab169033de0157751","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7sMx7mu0VxhEcrfATmLok6","service":"spop","name":"Leef Nu Het Kan","artist":"Jan Smit","album":"Leef (Deluxe Edition)","type":"song","duration":181,"albumart":"https://i.scdn.co/image/ab67616d0000b273d3264e93ac928b4571845f74","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:00+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1962" Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0jIcyUmf5aANj4ZAaHTizi","service":"spop","name":"Als Je Lacht","artist":"Jan Smit","album":"Stilte In De Storm","type":"song","duration":234,"albumart":"https://i.scdn.co/image/ab67616d0000b2739eada168548571df3bd0d680","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1jnUXW29r0JgYRcQmC3gIp","service":"spop","name":"Het Is Een Nacht... (Levensecht)","artist":"Guus Meeuwis","album":"Verbazing","type":"song","duration":225,"albumart":"https://i.scdn.co/image/ab67616d0000b273856a611ca5e21412716469fa","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:00+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3c28vYkrzU9nVqvJfbaSiu","service":"spop","name":"Amalia","artist":"Wesly Bronkhorst","album":"Amalia","type":"song","duration":157,"albumart":"https://i.scdn.co/image/ab67616d0000b27337a75c3ce8cf501e0d54e044","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0gq4UgDPGFdqpsWshU7dmv","service":"spop","name":"Vanavond (Uit M'n Bol)","artist":"Kris Kross Amsterdam","album":"Vanavond (Uit M'n Bol)","type":"song","duration":166,"albumart":"https://i.scdn.co/image/ab67616d0000b2737f53900c7289196d3045627f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioPushQueue Jul 16 10:40:00 foxsoftradio volumio[939]: info: CorePlayQueue::saveQueue Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreStateMachine::updateTrackBlock Jul 16 10:40:00 foxsoftradio volumio[939]: info: CorePlayQueue::getTrackBlock Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioPlay Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreStateMachine::play index 1 Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreStateMachine::stop Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreStateMachine::play index undefined Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 16 10:40:00 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:00 foxsoftradio volumio[939]: info: CoreStateMachine::startPlaybackTimer Jul 16 10:40:00 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:00 foxsoftradio volumio[939]: info: [1721119200728] ControllerSpotify::clearAddPlayTrack Jul 16 10:40:00 foxsoftradio volumio[939]: info: Sending Spotify command with payload to local API: /player/play Jul 16 10:40:00 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:00+02:00" level=debug msg="fetched first chunk of 16, total size is 8031960 bytes" Jul 16 10:40:00 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:00+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" Jul 16 10:40:00 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:00+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1560" Jul 16 10:40:00 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:00+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jul 16 10:40:00 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:00+02:00" level=info msg="loaded track \"Terug In De Tijd\" (uri: spotify:track:0vrKBjEBQAVn3sdhIXmpHE, paused: false, position: 0ms, duration: 187357ms)" Jul 16 10:40:00 foxsoftradio volumio[939]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jul 16 10:40:00 foxsoftradio volumio[939]: info: FusionDsp - ---- read samplerate from file: 44100 Jul 16 10:40:00 foxsoftradio volumio[939]: info: camilladsp stopping service pid 1225... Jul 16 10:40:00 foxsoftradio kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=1) Jul 16 10:40:00 foxsoftradio volumio[939]: info: camilladsp service terminated, instance 1 Jul 16 10:40:00 foxsoftradio volumio[939]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jul 16 10:40:00 foxsoftradio volumio[939]: info: camilladsp service started and running in background, instance 1 Jul 16 10:40:00 foxsoftradio volumio[939]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jul 16 10:40:00 foxsoftradio volumio[939]: info: FusionDsp - ---- read samplerate from file: 44100 Jul 16 10:40:00 foxsoftradio volumio[939]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jul 16 10:40:00 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:00+02:00" level=debug msg="fetched chunk 1/15, size: 524288" Jul 16 10:40:00 foxsoftradio volumio[939]: error: FusionDsp - WebSocket error: [object Object] Jul 16 10:40:01 foxsoftradio volumio[939]: info: camilladsp spawned new process with pid 1767, instance 1, run: true Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=trace msg="emitting websocket event: metadata" Jul 16 10:40:01 foxsoftradio volumio[939]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0vrKBjEBQAVn3sdhIXmpHE","name":"Terug In De Tijd","artist_names":["Yves Berendse"],"album_name":"Terug In De Tijd","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02e11300ca067bbc988f2e6f05","position":0,"duration":187357,"release_date":"year:2023 month:6 day:2","track_number":1,"disc_number":1}} Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=debug msg="fetched chunk 2/15, size: 524288" Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=trace msg="emitting websocket event: playing" Jul 16 10:40:01 foxsoftradio volumio[939]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0vrKBjEBQAVn3sdhIXmpHE","play_origin":"go-librespot"}} Jul 16 10:40:01 foxsoftradio volumio[939]: SPOTIFY: PUSH STATE SPOTIFY Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=debug msg="fetched chunk 3/15, size: 524288" Jul 16 10:40:01 foxsoftradio volumio[939]: SPOTIFY: {"status":"play","service":"spop","title":"Terug In De Tijd","artist":"Yves Berendse","album":"Terug In De Tijd","albumart":"https://i.scdn.co/image/ab67616d00001e02e11300ca067bbc988f2e6f05","uri":"spotify:track:0vrKBjEBQAVn3sdhIXmpHE","trackType":"spotify","seek":0,"duration":187,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreCommandRouter::servicePushState Jul 16 10:40:01 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:01 foxsoftradio volumio[939]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Terug In De Tijd","artist":"Yves Berendse","album":"Terug In De Tijd","albumart":"https://i.scdn.co/image/ab67616d00001e02e11300ca067bbc988f2e6f05","uri":"spotify:track:0vrKBjEBQAVn3sdhIXmpHE","trackType":"spotify","seek":0,"duration":187,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jul 16 10:40:01 foxsoftradio volumio[939]: verbose: CURRENT POSITION 1 Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreStateMachine::syncState stateService play Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreStateMachine::syncState currentStatus stop Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=debug msg="resolved context spotify:track:0vrKBjEBQAVn3sdhIXmpHE" Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=debug msg="loading track spotify:track:0vrKBjEBQAVn3sdhIXmpHE (paused: false, position: 159ms)" Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=trace msg="emitting websocket event: will_play" Jul 16 10:40:01 foxsoftradio volumio[939]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0vrKBjEBQAVn3sdhIXmpHE","play_origin":"go-librespot"}} Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:0vrKBjEBQAVn3sdhIXmpHE" Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=debug msg="requested aes key for file 754f013bd16ae72a92d987d8506833bf7cb77f8a, gid: 0vrKBjEBQAVn3sdhIXmpHE" Jul 16 10:40:01 foxsoftradio volumio[939]: SPOTIFY: PUSH STATE SPOTIFY Jul 16 10:40:01 foxsoftradio volumio[939]: SPOTIFY: {"status":"play","service":"spop","title":"Terug In De Tijd","artist":"Yves Berendse","album":"Terug In De Tijd","albumart":"https://i.scdn.co/image/ab67616d00001e02e11300ca067bbc988f2e6f05","uri":"spotify:track:0vrKBjEBQAVn3sdhIXmpHE","trackType":"spotify","seek":0,"duration":187,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreCommandRouter::servicePushState Jul 16 10:40:01 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:01 foxsoftradio volumio[939]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Terug In De Tijd","artist":"Yves Berendse","album":"Terug In De Tijd","albumart":"https://i.scdn.co/image/ab67616d00001e02e11300ca067bbc988f2e6f05","uri":"spotify:track:0vrKBjEBQAVn3sdhIXmpHE","trackType":"spotify","seek":0,"duration":187,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jul 16 10:40:01 foxsoftradio volumio[939]: verbose: CURRENT POSITION 1 Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreStateMachine::syncState stateService play Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 16 10:40:01 foxsoftradio volumio[939]: info: Received an update from plugin. extracting info from payload Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreStateMachine::pushState Jul 16 10:40:01 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioPushState Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreStateMachine::pushState Jul 16 10:40:01 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioPushState Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=debug msg="fetched first chunk of 16, total size is 8031960 bytes" Jul 16 10:40:01 foxsoftradio volumio[939]: info: touch_display: Setting screensaver timeout to 0 seconds. Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=trace msg="seek to 159ms (diff: 138ms, samples: 7011, bytes: 1855)" Jul 16 10:40:01 foxsoftradio volumio[939]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jul 16 10:40:01 foxsoftradio volumio[939]: info: FusionDsp - ---- read samplerate from file: 44100 Jul 16 10:40:01 foxsoftradio volumio[939]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=info msg="loaded track \"Terug In De Tijd\" (uri: spotify:track:0vrKBjEBQAVn3sdhIXmpHE, paused: false, position: 159ms, duration: 187357ms)" Jul 16 10:40:01 foxsoftradio volumio[939]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jul 16 10:40:01 foxsoftradio ntpd[727]: Soliciting pool server 213.109.127.82 Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=debug msg="fetched chunk 1/15, size: 524288" Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=trace msg="emitting websocket event: metadata" Jul 16 10:40:01 foxsoftradio volumio[939]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0vrKBjEBQAVn3sdhIXmpHE","name":"Terug In De Tijd","artist_names":["Yves Berendse"],"album_name":"Terug In De Tijd","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02e11300ca067bbc988f2e6f05","position":159,"duration":187357,"release_date":"year:2023 month:6 day:2","track_number":1,"disc_number":1}} Jul 16 10:40:01 foxsoftradio ntpd[727]: Soliciting pool server 193.123.37.231 Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=debug msg="fetched chunk 2/15, size: 524288" Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=trace msg="emitting websocket event: playing" Jul 16 10:40:01 foxsoftradio volumio[939]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0vrKBjEBQAVn3sdhIXmpHE","play_origin":"go-librespot"}} Jul 16 10:40:01 foxsoftradio volumio[939]: SPOTIFY: PUSH STATE SPOTIFY Jul 16 10:40:01 foxsoftradio volumio[939]: SPOTIFY: {"status":"play","service":"spop","title":"Terug In De Tijd","artist":"Yves Berendse","album":"Terug In De Tijd","albumart":"https://i.scdn.co/image/ab67616d00001e02e11300ca067bbc988f2e6f05","uri":"spotify:track:0vrKBjEBQAVn3sdhIXmpHE","trackType":"spotify","seek":159,"duration":187,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreCommandRouter::servicePushState Jul 16 10:40:01 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:01 foxsoftradio volumio[939]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Terug In De Tijd","artist":"Yves Berendse","album":"Terug In De Tijd","albumart":"https://i.scdn.co/image/ab67616d00001e02e11300ca067bbc988f2e6f05","uri":"spotify:track:0vrKBjEBQAVn3sdhIXmpHE","trackType":"spotify","seek":159,"duration":187,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jul 16 10:40:01 foxsoftradio volumio[939]: verbose: CURRENT POSITION 1 Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreStateMachine::syncState stateService play Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 16 10:40:01 foxsoftradio volumio[939]: info: Received an update from plugin. extracting info from payload Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreStateMachine::pushState Jul 16 10:40:01 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioPushState Jul 16 10:40:01 foxsoftradio ntpd[727]: Soliciting pool server 193.123.56.220 Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreStateMachine::pushState Jul 16 10:40:01 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioPushState Jul 16 10:40:01 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:01+02:00" level=debug msg="fetched chunk 3/15, size: 524288" Jul 16 10:40:01 foxsoftradio volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 16 10:40:02 foxsoftradio volumio[939]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jul 16 10:40:02 foxsoftradio volumio[939]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jul 16 10:40:02 foxsoftradio volumio[939]: info: Received Get System Version Jul 16 10:40:02 foxsoftradio volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 16 10:40:02 foxsoftradio volumio[939]: SPOTIFY: PUSH STATE SPOTIFY Jul 16 10:40:02 foxsoftradio volumio[939]: SPOTIFY: {"status":"play","service":"spop","title":"Terug In De Tijd","artist":"Yves Berendse","album":"Terug In De Tijd","albumart":"https://i.scdn.co/image/ab67616d00001e02e11300ca067bbc988f2e6f05","uri":"spotify:track:0vrKBjEBQAVn3sdhIXmpHE","trackType":"spotify","seek":159,"duration":187,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jul 16 10:40:02 foxsoftradio volumio[939]: info: CoreCommandRouter::servicePushState Jul 16 10:40:02 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:02 foxsoftradio volumio[939]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Terug In De Tijd","artist":"Yves Berendse","album":"Terug In De Tijd","albumart":"https://i.scdn.co/image/ab67616d00001e02e11300ca067bbc988f2e6f05","uri":"spotify:track:0vrKBjEBQAVn3sdhIXmpHE","trackType":"spotify","seek":159,"duration":187,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jul 16 10:40:02 foxsoftradio volumio[939]: verbose: CURRENT POSITION 1 Jul 16 10:40:02 foxsoftradio volumio[939]: info: CoreStateMachine::syncState stateService play Jul 16 10:40:02 foxsoftradio volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 16 10:40:02 foxsoftradio volumio[939]: info: Received an update from plugin. extracting info from payload Jul 16 10:40:02 foxsoftradio volumio[939]: info: CoreStateMachine::pushState Jul 16 10:40:02 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:02 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioPushState Jul 16 10:40:02 foxsoftradio volumio[939]: info: CoreStateMachine::pushState Jul 16 10:40:02 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:02 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioPushState Jul 16 10:40:02 foxsoftradio volumio[939]: info: Received Get System Info Jul 16 10:40:02 foxsoftradio volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 16 10:40:02 foxsoftradio volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 16 10:40:02 foxsoftradio volumio[939]: info: Discovery: Getting this device information Jul 16 10:40:02 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioGetState Jul 16 10:40:02 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:02 foxsoftradio volumio[939]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 16 10:40:02 foxsoftradio ntpd[727]: Soliciting pool server 158.101.213.248 Jul 16 10:40:02 foxsoftradio ntpd[727]: Soliciting pool server 95.85.21.89 Jul 16 10:40:02 foxsoftradio ntpd[727]: Soliciting pool server 209.250.249.159 Jul 16 10:40:03 foxsoftradio ntpd[727]: Soliciting pool server 45.138.55.62 Jul 16 10:40:03 foxsoftradio ntpd[727]: Soliciting pool server 51.15.20.83 Jul 16 10:40:03 foxsoftradio ntpd[727]: Soliciting pool server 185.224.145.68 Jul 16 10:40:04 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioGetState Jul 16 10:40:04 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:04 foxsoftradio ntpd[727]: Soliciting pool server 81.172.225.142 Jul 16 10:40:04 foxsoftradio ntpd[727]: Soliciting pool server 86.80.166.233 Jul 16 10:40:04 foxsoftradio ntpd[727]: Soliciting pool server 95.211.123.72 Jul 16 10:40:05 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioSeek Jul 16 10:40:05 foxsoftradio volumio[939]: info: CoreStateMachine::seek Jul 16 10:40:05 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:05 foxsoftradio volumio[939]: info: TRACKBLOCK {"uri":"spotify:track:0vrKBjEBQAVn3sdhIXmpHE","service":"spop","name":"Terug In De Tijd","artist":"Yves Berendse","album":"Terug In De Tijd","type":"song","duration":187,"albumart":"https://i.scdn.co/image/ab67616d0000b273e11300ca067bbc988f2e6f05","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify","channels":2} Jul 16 10:40:05 foxsoftradio volumio[939]: info: CoreStateMachine::startPlaybackTimer Jul 16 10:40:05 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:05 foxsoftradio volumio[939]: info: Spotify seek to: 28000 Jul 16 10:40:05 foxsoftradio volumio[939]: info: Sending Spotify command with payload to local API: /player/seek Jul 16 10:40:05 foxsoftradio volumio[939]: info: CoreStateMachine::pushState Jul 16 10:40:05 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:05 foxsoftradio volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 16 10:40:05 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioPushState Jul 16 10:40:05 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:05+02:00" level=debug msg="seek track to 28000ms" Jul 16 10:40:05 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:05+02:00" level=trace msg="seek to 28000ms (diff: 129ms, samples: 1234800, bytes: 1152819)" Jul 16 10:40:05 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:05+02:00" level=debug msg="fetched chunk 4/15, size: 524288" Jul 16 10:40:05 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:05+02:00" level=debug msg="fetched chunk 5/15, size: 524288" Jul 16 10:40:05 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:05+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 16 10:40:05 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:05+02:00" level=trace msg="emitting websocket event: seek" Jul 16 10:40:05 foxsoftradio volumio[939]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:0vrKBjEBQAVn3sdhIXmpHE","position":28000,"duration":187357,"play_origin":"go-librespot"}} Jul 16 10:40:05 foxsoftradio volumio[939]: SPOTIFY: PUSH STATE SPOTIFY Jul 16 10:40:05 foxsoftradio volumio[939]: SPOTIFY: {"status":"play","service":"spop","title":"Terug In De Tijd","artist":"Yves Berendse","album":"Terug In De Tijd","albumart":"https://i.scdn.co/image/ab67616d00001e02e11300ca067bbc988f2e6f05","uri":"spotify:track:0vrKBjEBQAVn3sdhIXmpHE","trackType":"spotify","seek":28000,"duration":187,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jul 16 10:40:05 foxsoftradio volumio[939]: info: CoreCommandRouter::servicePushState Jul 16 10:40:05 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:05 foxsoftradio volumio[939]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Terug In De Tijd","artist":"Yves Berendse","album":"Terug In De Tijd","albumart":"https://i.scdn.co/image/ab67616d00001e02e11300ca067bbc988f2e6f05","uri":"spotify:track:0vrKBjEBQAVn3sdhIXmpHE","trackType":"spotify","seek":28000,"duration":187,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jul 16 10:40:05 foxsoftradio volumio[939]: verbose: CURRENT POSITION 1 Jul 16 10:40:05 foxsoftradio volumio[939]: info: CoreStateMachine::syncState stateService play Jul 16 10:40:05 foxsoftradio volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 16 10:40:05 foxsoftradio volumio[939]: info: Received an update from plugin. extracting info from payload Jul 16 10:40:05 foxsoftradio volumio[939]: info: CoreStateMachine::pushState Jul 16 10:40:05 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:05 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioPushState Jul 16 10:40:05 foxsoftradio volumio[939]: info: CoreStateMachine::pushState Jul 16 10:40:05 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:40:05 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioPushState Jul 16 10:40:05 foxsoftradio ntpd[727]: Soliciting pool server 45.83.205.227 Jul 16 10:40:05 foxsoftradio ntpd[727]: Soliciting pool server 2a09:0:2:0:7c3:11b7:71e6:810d Jul 16 10:40:05 foxsoftradio ntpd[727]: Soliciting pool server 162.159.200.1 Jul 16 10:40:06 foxsoftradio ntpd[727]: Soliciting pool server 167.99.42.106 Jul 16 10:40:07 foxsoftradio ntpd[727]: Soliciting pool server 188.166.95.178 Jul 16 10:40:08 foxsoftradio ntpd[727]: Soliciting pool server 94.198.159.15 Jul 16 10:40:42 foxsoftradio ntpd[727]: receive: Unexpected origin timestamp 0xea40b069.97744e5a does not match aorg 0000000000.00000000 from server@193.123.56.220 xmt 0xea40b08a.57961b3c Jul 16 10:40:42 foxsoftradio ntpd[727]: receive: Unexpected origin timestamp 0xea40b069.97753da1 does not match aorg 0000000000.00000000 from server@213.109.127.82 xmt 0xea40b08a.57fac918 Jul 16 10:40:42 foxsoftradio ntpd[727]: receive: Unexpected origin timestamp 0xea40b069.97701f61 does not match aorg 0000000000.00000000 from server@185.224.145.68 xmt 0xea40b08a.57b77d16 Jul 16 10:40:42 foxsoftradio ntpd[727]: Soliciting pool server 193.178.197.114 Jul 16 10:40:43 foxsoftradio ntpd[727]: Soliciting pool server 45.159.204.28 Jul 16 10:40:46 foxsoftradio go-librespot[1531]: time="2024-07-16T10:40:46+02:00" level=debug msg="fetched chunk 6/15, size: 524288" Jul 16 10:40:52 foxsoftradio volumio[939]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 16 10:40:55 foxsoftradio volumio[939]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jul 16 10:40:55 foxsoftradio volumio[939]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jul 16 10:40:55 foxsoftradio volumio[939]: info: Creating Spotify config file Jul 16 10:40:55 foxsoftradio volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 16 10:40:55 foxsoftradio volumio[939]: info: Spotify config file written Jul 16 10:40:55 foxsoftradio sudo[1781]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jul 16 10:40:55 foxsoftradio sudo[1781]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 16 10:40:55 foxsoftradio systemd[1]: Stopping go-librespot Daemon... Jul 16 10:40:55 foxsoftradio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Jul 16 10:40:55 foxsoftradio systemd[1]: go-librespot-daemon.service: Succeeded. Jul 16 10:40:55 foxsoftradio systemd[1]: Stopped go-librespot Daemon. Jul 16 10:40:55 foxsoftradio volumio[939]: info: Connection to go-librespot Websocket closed Jul 16 10:40:55 foxsoftradio systemd[1]: Started go-librespot Daemon. Jul 16 10:40:55 foxsoftradio go-librespot[1783]: Librespot-go daemon starting... Jul 16 10:40:55 foxsoftradio sudo[1781]: pam_unix(sudo:session): session closed for user root Jul 16 10:40:55 foxsoftradio go-librespot[1783]: time="2024-07-16T10:40:55+02:00" level=info msg="generated new device id: b7379cb2355548f388988c81d8bf77f117887589" Jul 16 10:40:55 foxsoftradio go-librespot[1783]: time="2024-07-16T10:40:55+02:00" level=debug msg="stored credentials found for kpteqon2r60fkhhynbezrmqlo" Jul 16 10:40:55 foxsoftradio go-librespot[1783]: time="2024-07-16T10:40:55+02:00" level=debug msg="obtained new client token: AACtdSlfmPlC37zLdvImzk7luW3uucQA0RbzUmo6p4hdbysNRBUQObOEYDrNL+HVgrMpzDweyuK8gundSylkGdobcqqKoUlvxInEO6NTm/BmcOVK1parIkEz6Z+W/X+llbmDXgFWjssPfVGp57+/hz7BvBzuI2SlyxKF4ATqEksVuKOSyp4uSGGaz4AWr1NC8LssDHnOKFLbgeG+gRy0EkGzbuYxHadsg0dI9XFEJ82ZyWvis76f+k+y5Ws=" Jul 16 10:40:55 foxsoftradio go-librespot[1783]: time="2024-07-16T10:40:55+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 16 10:40:55 foxsoftradio go-librespot[1783]: time="2024-07-16T10:40:55+02:00" level=debug msg="completed keyexchange" Jul 16 10:40:55 foxsoftradio kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=1) Jul 16 10:40:55 foxsoftradio volumio[939]: info: camilladsp spawned new process with pid 1791, instance 1, run: true Jul 16 10:40:56 foxsoftradio go-librespot[1783]: time="2024-07-16T10:40:56+02:00" level=debug msg="completed challenge" Jul 16 10:40:56 foxsoftradio go-librespot[1783]: time="2024-07-16T10:40:56+02:00" level=debug msg="authenticated as kpteqon2r60fkhhynbezrmqlo" Jul 16 10:40:56 foxsoftradio go-librespot[1783]: time="2024-07-16T10:40:56+02:00" level=debug msg="authenticated as kpteqon2r60fkhhynbezrmqlo" Jul 16 10:40:56 foxsoftradio go-librespot[1783]: time="2024-07-16T10:40:56+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jul 16 10:40:56 foxsoftradio go-librespot[1783]: time="2024-07-16T10:40:56+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jul 16 10:40:56 foxsoftradio go-librespot[1783]: time="2024-07-16T10:40:56+02:00" level=debug msg="dealer connection opened" Jul 16 10:40:56 foxsoftradio go-librespot[1783]: time="2024-07-16T10:40:56+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jul 16 10:40:56 foxsoftradio go-librespot[1783]: time="2024-07-16T10:40:56+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jul 16 10:40:56 foxsoftradio go-librespot[1783]: time="2024-07-16T10:40:56+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jul 16 10:40:56 foxsoftradio go-librespot[1783]: time="2024-07-16T10:40:56+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jul 16 10:40:56 foxsoftradio go-librespot[1783]: time="2024-07-16T10:40:56+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Jul 16 10:40:56 foxsoftradio go-librespot[1783]: time="2024-07-16T10:40:56+02:00" level=debug msg="received connection id: ODc5MWIyNDctN2Q2OS00YzkzLTk1ZjktNTA3NTBiZjI0Y2ZkK2RlYWxlcit0Y3A6Ly9nZXc0LWRlYWxlci1hLXpzemMuZ2V3NC5zcG90aWZ5Lm5ldDo1NzAwKzQxNjI4NDlFQjhCNzUxMUM0RTcwMDg3MUIwMDQ0Q0ZDRjNCRERCQzJFNDg5NzA3MUUzNkVBN0E3OTk4OEI0M0I=" Jul 16 10:40:56 foxsoftradio go-librespot[1783]: time="2024-07-16T10:40:56+02:00" level=debug msg="put connect state because NEW_DEVICE" Jul 16 10:40:58 foxsoftradio volumio[939]: info: Initializing connection to go-librespot Websocket Jul 16 10:40:58 foxsoftradio go-librespot[1783]: time="2024-07-16T10:40:58+02:00" level=debug msg="new websocket client" Jul 16 10:40:58 foxsoftradio volumio[939]: info: Connection to go-librespot Websocket established Jul 16 10:40:58 foxsoftradio volumio[939]: info: go-librespot daemon successfully initialized Jul 16 10:41:01 foxsoftradio volumio[939]: info: Getting Spotify volume Jul 16 10:41:01 foxsoftradio volumio[939]: info: Spotify volume: 100 Jul 16 10:41:01 foxsoftradio volumio[939]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Jul 16 10:41:01 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioGetState Jul 16 10:41:01 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:41:01 foxsoftradio volumio[939]: info: Initializing connection to go-librespot Websocket Jul 16 10:41:01 foxsoftradio go-librespot[1783]: time="2024-07-16T10:41:01+02:00" level=debug msg="new websocket client" Jul 16 10:41:01 foxsoftradio volumio[939]: info: Connection to go-librespot Websocket established Jul 16 10:41:04 foxsoftradio volumio[939]: info: Getting Spotify volume Jul 16 10:41:04 foxsoftradio volumio[939]: info: Spotify volume: 100 Jul 16 10:41:04 foxsoftradio volumio[939]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Jul 16 10:41:04 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioGetState Jul 16 10:41:04 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:41:17 foxsoftradio volumio[939]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 16 10:41:17 foxsoftradio volumio[939]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jul 16 10:41:17 foxsoftradio volumio[939]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 16 10:41:17 foxsoftradio volumio[939]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 16 10:41:17 foxsoftradio volumio[939]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 16 10:41:20 foxsoftradio go-librespot[1783]: time="2024-07-16T10:41:20+02:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Jul 16 10:41:20 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Jul 16 10:41:20 foxsoftradio volumio[939]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 16 10:41:20 foxsoftradio sudo[1799]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service Jul 16 10:41:20 foxsoftradio sudo[1799]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 16 10:41:20 foxsoftradio volumio[939]: info: Disabling plugin spop Jul 16 10:41:20 foxsoftradio volumio[939]: info: Done. Jul 16 10:41:20 foxsoftradio volumio[939]: info: Connection to go-librespot Websocket closed Jul 16 10:41:20 foxsoftradio systemd[1]: Stopping go-librespot Daemon... Jul 16 10:41:20 foxsoftradio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Jul 16 10:41:20 foxsoftradio systemd[1]: go-librespot-daemon.service: Succeeded. Jul 16 10:41:20 foxsoftradio systemd[1]: Stopped go-librespot Daemon. Jul 16 10:41:20 foxsoftradio volumio[939]: info: Connection to go-librespot Websocket closed Jul 16 10:41:20 foxsoftradio volumio[939]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 16 10:41:20 foxsoftradio volumio[939]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 16 10:41:20 foxsoftradio sudo[1799]: pam_unix(sudo:session): session closed for user root Jul 16 10:41:20 foxsoftradio volumio[939]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 16 10:41:29 foxsoftradio volumio[939]: info: CoreCommandRouter::volumioPrevious Jul 16 10:41:29 foxsoftradio volumio[939]: info: CoreStateMachine::previous Jul 16 10:41:29 foxsoftradio volumio[939]: info: CorePlayQueue::getTrack 1 Jul 16 10:41:29 foxsoftradio volumio[939]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 16 10:41:29 foxsoftradio volumio[939]: TypeError: Cannot read property 'seek' of undefined Jul 16 10:41:29 foxsoftradio volumio[939]: at CoreStateMachine.previous (/volumio/app/statemachine.js:1323:60) Jul 16 10:41:29 foxsoftradio volumio[939]: at CoreCommandRouter.volumioPrevious (/volumio/app/index.js:95:28) Jul 16 10:41:29 foxsoftradio volumio[939]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:267:33) Jul 16 10:41:29 foxsoftradio volumio[939]: at Socket.emit (events.js:315:20) Jul 16 10:41:29 foxsoftradio volumio[939]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jul 16 10:41:29 foxsoftradio volumio[939]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Jul 16 10:41:29 foxsoftradio volumio[939]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 16 10:41:30 foxsoftradio sudo[1852]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-16 10:40 Jul 16 10:41:30 foxsoftradio sudo[1852]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"