-- Logs begin at Fri 2024-10-25 07:45:32 UTC, end at Mon 2024-10-28 14:27:52 UTC. -- Oct 28 14:26:03 volumio go-librespot[1202]: time="2024-10-28T14:26:03Z" level=debug msg="fetched chunk 6/15, size: 524288" uri="spotify:track:5vNRhkKd0yEAg8suGBpjeY" Oct 28 14:26:04 volumio kernel: hwmon hwmon1: Undervoltage detected! Oct 28 14:26:10 volumio kernel: hwmon hwmon1: Voltage normalised Oct 28 14:26:14 volumio go-librespot[1202]: time="2024-10-28T14:26:14Z" level=debug msg="fetched chunk 7/15, size: 524288" uri="spotify:track:5vNRhkKd0yEAg8suGBpjeY" Oct 28 14:26:16 volumio volumio[958]: Searching plugin music_service/spop Oct 28 14:26:16 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , search Oct 28 14:26:17 volumio volumio[958]: info: All search sources collected, pushing search results Oct 28 14:26:19 volumio volumio[958]: Searching plugin music_service/spop Oct 28 14:26:19 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , search Oct 28 14:26:20 volumio kernel: hwmon hwmon1: Undervoltage detected! Oct 28 14:26:21 volumio volumio[958]: info: All search sources collected, pushing search results Oct 28 14:26:24 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 28 14:26:24 volumio volumio[958]: info: In handleBrowseUri, curUri=spotify:artist:2x8vG4f0HYXzMEo3xNsoiI Oct 28 14:26:25 volumio go-librespot[1202]: time="2024-10-28T14:26:25Z" level=debug msg="fetched chunk 8/15, size: 524288" uri="spotify:track:5vNRhkKd0yEAg8suGBpjeY" Oct 28 14:26:26 volumio volumio[958]: info: Preload queue cleared Oct 28 14:26:26 volumio volumio[958]: info: Preloading song: spotify:track:6Obb1FCQLZrVRvzXWdgDma Oct 28 14:26:26 volumio volumio[958]: info: Preloading song: spotify:track:3bDUHKloYp3LlAUXJTI4O4 Oct 28 14:26:26 volumio volumio[958]: info: Preloading song: spotify:track:05QrFuWM7KDohFMmXzLOsL Oct 28 14:26:26 volumio volumio[958]: info: Preloading song: spotify:track:3BRSgDlShzyigvcKnB3L0c Oct 28 14:26:26 volumio volumio[958]: info: Preloading song: spotify:track:3pIG1sxniqvPXGcp2Tgky0 Oct 28 14:26:26 volumio volumio[958]: info: Preloading song: spotify:track:5Ck2bAipFCqcmGc24dlHu7 Oct 28 14:26:26 volumio volumio[958]: info: Preloading song: spotify:track:6pxza2NYAMgI5Ngh0uvmy3 Oct 28 14:26:26 volumio volumio[958]: info: Preloading song: spotify:track:6RfGi5YVgwdlqxwlpq95sQ Oct 28 14:26:26 volumio volumio[958]: info: Preloading song: spotify:track:5JGTcHUa3aBI6PUPVP2K5f Oct 28 14:26:26 volumio volumio[958]: info: Preloading song: spotify:track:1oClfMl07OFOUdccV0tV17 Oct 28 14:26:26 volumio volumio[958]: info: Preload queue cleared Oct 28 14:26:26 volumio volumio[958]: info: Preload queue cleared Oct 28 14:26:28 volumio volumio[958]: info: No valid Plugin REST Endpoint Oct 28 14:26:31 volumio kernel: hwmon hwmon1: Voltage normalised Oct 28 14:26:33 volumio kernel: hwmon hwmon1: Undervoltage detected! Oct 28 14:26:36 volumio volumio[958]: info: Preload queue cleared Oct 28 14:26:36 volumio volumio[958]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 28 14:26:36 volumio volumio[958]: info: CoreStateMachine::ClearQueue Oct 28 14:26:36 volumio volumio[958]: info: CoreStateMachine::stop Oct 28 14:26:36 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 14:26:36 volumio volumio[958]: info: CoreStateMachine::stPlaybackTimer Oct 28 14:26:36 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Oct 28 14:26:36 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Oct 28 14:26:36 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:26:36 volumio volumio[958]: info: CorePlayQueue::getTrack 0 Oct 28 14:26:36 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 14:26:36 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:26:36 volumio volumio[958]: info: CoreStateMachine::serviceStop Oct 28 14:26:36 volumio volumio[958]: info: CorePlayQueue::getTrack 0 Oct 28 14:26:36 volumio volumio[958]: info: CoreCommandRouter::serviceStop Oct 28 14:26:36 volumio volumio[958]: info: Spotify Stop Oct 28 14:26:36 volumio volumio[958]: SPOTIFY: SPOTIFY STOP Oct 28 14:26:36 volumio volumio[958]: SPOTIFY: {"status":"play","position":0,"title":"APT.","artist":"ROSÉ","album":"APT.","albumart":"https://i.scdn.co/image/ab67616d0000b273f8c8297efc6022534f1357e1","uri":"spotify:track:5vNRhkKd0yEAg8suGBpjeY","trackType":"spotify","codec":"ogg","seek":0,"duration":169,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":null,"repeatSingle":false,"consume":false,"volume":"","dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Oct 28 14:26:36 volumio volumio[958]: info: Sending Spotify command to local API: /player/pause Oct 28 14:26:36 volumio volumio[958]: info: CorePlayQueue::clearPlayQueue Oct 28 14:26:36 volumio volumio[958]: info: CorePlayQueue::saveQueue Oct 28 14:26:36 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue Oct 28 14:26:36 volumio volumio[958]: info: CoreStateMachine::addQueueItems Oct 28 14:26:36 volumio volumio[958]: info: CorePlayQueue::addQueueItems Oct 28 14:26:36 volumio volumio[958]: info: Preload queue cleared Oct 28 14:26:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6Obb1FCQLZrVRvzXWdgDma Oct 28 14:26:36 volumio volumio[958]: info: Exploding uri spotify:track:6Obb1FCQLZrVRvzXWdgDma in service spop Oct 28 14:26:36 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:6Obb1FCQLZrVRvzXWdgDma Oct 28 14:26:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:3bDUHKloYp3LlAUXJTI4O4 Oct 28 14:26:36 volumio volumio[958]: info: Exploding uri spotify:track:3bDUHKloYp3LlAUXJTI4O4 in service spop Oct 28 14:26:36 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:3bDUHKloYp3LlAUXJTI4O4 Oct 28 14:26:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:05QrFuWM7KDohFMmXzLOsL Oct 28 14:26:36 volumio volumio[958]: info: Exploding uri spotify:track:05QrFuWM7KDohFMmXzLOsL in service spop Oct 28 14:26:36 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:05QrFuWM7KDohFMmXzLOsL Oct 28 14:26:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:3BRSgDlShzyigvcKnB3L0c Oct 28 14:26:36 volumio volumio[958]: info: Exploding uri spotify:track:3BRSgDlShzyigvcKnB3L0c in service spop Oct 28 14:26:36 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:3BRSgDlShzyigvcKnB3L0c Oct 28 14:26:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:3pIG1sxniqvPXGcp2Tgky0 Oct 28 14:26:36 volumio volumio[958]: info: Exploding uri spotify:track:3pIG1sxniqvPXGcp2Tgky0 in service spop Oct 28 14:26:36 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:3pIG1sxniqvPXGcp2Tgky0 Oct 28 14:26:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:5Ck2bAipFCqcmGc24dlHu7 Oct 28 14:26:36 volumio volumio[958]: info: Exploding uri spotify:track:5Ck2bAipFCqcmGc24dlHu7 in service spop Oct 28 14:26:36 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:5Ck2bAipFCqcmGc24dlHu7 Oct 28 14:26:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6pxza2NYAMgI5Ngh0uvmy3 Oct 28 14:26:36 volumio volumio[958]: info: Exploding uri spotify:track:6pxza2NYAMgI5Ngh0uvmy3 in service spop Oct 28 14:26:36 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:6pxza2NYAMgI5Ngh0uvmy3 Oct 28 14:26:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6RfGi5YVgwdlqxwlpq95sQ Oct 28 14:26:36 volumio volumio[958]: info: Exploding uri spotify:track:6RfGi5YVgwdlqxwlpq95sQ in service spop Oct 28 14:26:36 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:6RfGi5YVgwdlqxwlpq95sQ Oct 28 14:26:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:5JGTcHUa3aBI6PUPVP2K5f Oct 28 14:26:36 volumio volumio[958]: info: Exploding uri spotify:track:5JGTcHUa3aBI6PUPVP2K5f in service spop Oct 28 14:26:36 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:5JGTcHUa3aBI6PUPVP2K5f Oct 28 14:26:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:1oClfMl07OFOUdccV0tV17 Oct 28 14:26:36 volumio volumio[958]: info: Exploding uri spotify:track:1oClfMl07OFOUdccV0tV17 in service spop Oct 28 14:26:36 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:1oClfMl07OFOUdccV0tV17 Oct 28 14:26:36 volumio go-librespot[1202]: time="2024-10-28T14:26:36Z" level=debug msg="fetched chunk 9/15, size: 524288" uri="spotify:track:5vNRhkKd0yEAg8suGBpjeY" Oct 28 14:26:36 volumio go-librespot[1202]: time="2024-10-28T14:26:36Z" level=debug msg="pause track at 67534ms" Oct 28 14:26:37 volumio go-librespot[1202]: time="2024-10-28T14:26:37Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:26:37 volumio go-librespot[1202]: time="2024-10-28T14:26:37Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:26:37 volumio go-librespot[1202]: time="2024-10-28T14:26:37Z" level=trace msg="emitting websocket event: paused" Oct 28 14:26:37 volumio volumio[958]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5vNRhkKd0yEAg8suGBpjeY","play_origin":"go-librespot"}} Oct 28 14:26:37 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:26:37 volumio volumio[958]: SPOTIFY: {"status":"pause","service":"spop","title":"APT.","artist":"ROSÉ, Bruno Mars","album":"APT.","albumart":"https://i.scdn.co/image/ab67616d00001e02f8c8297efc6022534f1357e1","uri":"spotify:track:5vNRhkKd0yEAg8suGBpjeY","trackType":"spotify","seek":67000,"duration":169,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:26:37 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:26:37 volumio volumio[958]: info: CorePlayQueue::getTrack 0 Oct 28 14:26:37 volumio volumio[958]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"APT.","artist":"ROSÉ, Bruno Mars","album":"APT.","albumart":"https://i.scdn.co/image/ab67616d00001e02f8c8297efc6022534f1357e1","uri":"spotify:track:5vNRhkKd0yEAg8suGBpjeY","trackType":"spotify","seek":67000,"duration":169,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:26:37 volumio volumio[958]: verbose: CURRENT POSITION 0 Oct 28 14:26:37 volumio volumio[958]: info: CoreStateMachine::syncState stateService pause Oct 28 14:26:37 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus stop Oct 28 14:26:37 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:26:37 volumio volumio[958]: info: CorePlayQueue::getTrack 0 Oct 28 14:26:37 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 14:26:37 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:26:37 volumio volumio[958]: info: touch_display: Setting screensaver timeout to 120 seconds. Oct 28 14:26:37 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6RfGi5YVgwdlqxwlpq95sQ","service":"spop","name":"No Risk, no Fun (feat. Lina Larissa Strahl, Emilio Moutaoukkil)","artist":"Bibi und Tina","album":"Bibi und Tina: VOLL VERHEXT! (Der Original-Soundtrack zum Kinofilm)","type":"song","duration":159,"albumart":"https://i.scdn.co/image/ab67616d0000b2733ebf3820c34e28534dd73501","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 28 14:26:37 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3pIG1sxniqvPXGcp2Tgky0","service":"spop","name":"98 Prozent (feat. Mavie Hörbiger)","artist":"Bibi und Tina","album":"Bibi und Tina: VOLL VERHEXT! (Der Original-Soundtrack zum Kinofilm)","type":"song","duration":141,"albumart":"https://i.scdn.co/image/ab67616d0000b2733ebf3820c34e28534dd73501","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 28 14:26:37 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6Obb1FCQLZrVRvzXWdgDma","service":"spop","name":"Bibi und Tina Lied","artist":"Bibi und Tina","album":"Folge 1: Das Fohlen","type":"song","duration":78,"albumart":"https://i.scdn.co/image/ab67616d0000b27318a585a08c1172a01c460a9d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 28 14:26:37 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3bDUHKloYp3LlAUXJTI4O4","service":"spop","name":"Up, up, up (Nobody’s perfect) [feat. Lina Larissa Strahl]","artist":"Bibi und Tina","album":"Bibi und Tina (Der Original-Soundtrack zum Kinofilm)","type":"song","duration":158,"albumart":"https://i.scdn.co/image/ab67616d0000b273ea51a99d4fdd3d1a27d8b8f1","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 28 14:26:37 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:05QrFuWM7KDohFMmXzLOsL","service":"spop","name":"Mädchen gegen Jungs (feat. Lina Larissa Strahl, Lisa-Marie Koroll, Phil Laude, Louis H.)","artist":"Bibi und Tina","album":"Bibi und Tina: Mädchen gegen Jungs (Der Original-Soundtrack zum Kinofilm)","type":"song","duration":163,"albumart":"https://i.scdn.co/image/ab67616d0000b273ef840303da8adc7be282090e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 28 14:26:37 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5JGTcHUa3aBI6PUPVP2K5f","service":"spop","name":"Kapitel 06: Das unbekannte Pferd (Folge 115)","artist":"Bibi und Tina","album":"Folge 115: Das unbekannte Pferd","type":"song","duration":194,"albumart":"https://i.scdn.co/image/ab67616d0000b27375243d0cc865c4e1bc50e8ca","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 28 14:26:37 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1oClfMl07OFOUdccV0tV17","service":"spop","name":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","type":"song","duration":183,"albumart":"https://i.scdn.co/image/ab67616d0000b273fed9b8c3641e3c7b70863eda","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 28 14:26:37 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5Ck2bAipFCqcmGc24dlHu7","service":"spop","name":"Feuer, Feuer! (feat. Lina Larissa Strahl)","artist":"Bibi und Tina","album":"Bibi und Tina: Mädchen gegen Jungs (Der Original-Soundtrack zum Kinofilm)","type":"song","duration":171,"albumart":"https://i.scdn.co/image/ab67616d0000b273ef840303da8adc7be282090e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 28 14:26:37 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6pxza2NYAMgI5Ngh0uvmy3","service":"spop","name":"Kapitel 08: Ärger mit dem Grafen (Folge 101)","artist":"Bibi und Tina","album":"Folge 101: Ärger mit dem Grafen","type":"song","duration":92,"albumart":"https://i.scdn.co/image/ab67616d0000b2737f40a35f27190133039d4778","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 28 14:26:37 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3BRSgDlShzyigvcKnB3L0c","service":"spop","name":"Mädchen auf dem Pferd (feat. Fabian Buch)","artist":"Bibi und Tina","album":"Bibi und Tina (Der Original-Soundtrack zum Kinofilm)","type":"song","duration":151,"albumart":"https://i.scdn.co/image/ab67616d0000b273ea51a99d4fdd3d1a27d8b8f1","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 28 14:26:37 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue Oct 28 14:26:37 volumio volumio[958]: info: CorePlayQueue::saveQueue Oct 28 14:26:37 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Oct 28 14:26:37 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Oct 28 14:26:37 volumio volumio[958]: info: CoreCommandRouter::volumioPlay Oct 28 14:26:37 volumio volumio[958]: info: CoreStateMachine::play index 5 Oct 28 14:26:37 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 14:26:37 volumio volumio[958]: info: CoreStateMachine::stop Oct 28 14:26:37 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 14:26:37 volumio volumio[958]: info: CoreStateMachine::play index undefined Oct 28 14:26:37 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 14:26:37 volumio volumio[958]: info: CorePlayQueue::getTrack 5 Oct 28 14:26:37 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer Oct 28 14:26:37 volumio volumio[958]: info: CorePlayQueue::getTrack 5 Oct 28 14:26:37 volumio volumio[958]: info: [1730125597561] ControllerSpotify::clearAddPlayTrack Oct 28 14:26:37 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play Oct 28 14:26:37 volumio go-librespot[1202]: time="2024-10-28T14:26:37Z" level=debug msg="resolved context of track" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:26:37 volumio go-librespot[1202]: time="2024-10-28T14:26:37Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:26:37 volumio go-librespot[1202]: time="2024-10-28T14:26:37Z" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:26:37 volumio go-librespot[1202]: time="2024-10-28T14:26:37Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:26:37 volumio go-librespot[1202]: time="2024-10-28T14:26:37Z" level=trace msg="emitting websocket event: will_play" Oct 28 14:26:37 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5Ck2bAipFCqcmGc24dlHu7","play_origin":"go-librespot"}} Oct 28 14:26:37 volumio go-librespot[1202]: time="2024-10-28T14:26:37Z" level=debug msg="selected format OGG_VORBIS_320 (1e852dd0273759e08380192e844624d792e8b9e2)" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:26:37 volumio go-librespot[1202]: time="2024-10-28T14:26:37Z" level=debug msg="requested aes key for file 1e852dd0273759e08380192e844624d792e8b9e2, gid: 5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:26:38 volumio go-librespot[1202]: time="2024-10-28T14:26:38Z" level=debug msg="fetched first chunk of 14, total size is 7334044 bytes" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:26:38 volumio go-librespot[1202]: time="2024-10-28T14:26:38Z" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:26:38 volumio go-librespot[1202]: time="2024-10-28T14:26:38Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Oct 28 14:26:38 volumio go-librespot[1202]: time="2024-10-28T14:26:38Z" level=info msg="loaded track \"Feuer, Feuer! (feat. Lina Larissa Strahl)\" (paused: false, position: 0ms, duration: 171978ms, prefetched: false)" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:26:38 volumio go-librespot[1202]: time="2024-10-28T14:26:38Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:26:38 volumio go-librespot[1202]: time="2024-10-28T14:26:38Z" level=debug msg="fetched chunk 3/13, size: 524288" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:26:38 volumio go-librespot[1202]: time="2024-10-28T14:26:38Z" level=trace msg="scheduling prefetch in 142s" Oct 28 14:26:38 volumio go-librespot[1202]: time="2024-10-28T14:26:38Z" level=trace msg="emitting websocket event: metadata" Oct 28 14:26:38 volumio volumio[958]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5Ck2bAipFCqcmGc24dlHu7","name":"Feuer, Feuer! (feat. Lina Larissa Strahl)","artist_names":["Bibi und Tina","Peter Plate","Ulf Leo Sommer","Lina Larissa Strahl"],"album_name":"Bibi und Tina: Mädchen gegen Jungs (Der Original-Soundtrack zum Kinofilm)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02ef840303da8adc7be282090e","position":0,"duration":171978,"release_date":"year:2016 month:1 day:15","track_number":3,"disc_number":1}} Oct 28 14:26:38 volumio go-librespot[1202]: time="2024-10-28T14:26:38Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:26:38 volumio go-librespot[1202]: time="2024-10-28T14:26:38Z" level=trace msg="emitting websocket event: playing" Oct 28 14:26:38 volumio volumio[958]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5Ck2bAipFCqcmGc24dlHu7","play_origin":"go-librespot"}} Oct 28 14:26:38 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:26:38 volumio volumio[958]: SPOTIFY: {"status":"play","service":"spop","title":"Feuer, Feuer! (feat. Lina Larissa Strahl)","artist":"Bibi und Tina, Peter Plate, Ulf Leo Sommer, Lina Larissa Strahl","album":"Bibi und Tina: Mädchen gegen Jungs (Der Original-Soundtrack zum Kinofilm)","albumart":"https://i.scdn.co/image/ab67616d00001e02ef840303da8adc7be282090e","uri":"spotify:track:5Ck2bAipFCqcmGc24dlHu7","trackType":"spotify","seek":0,"duration":171,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:26:38 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:26:38 volumio volumio[958]: info: CorePlayQueue::getTrack 5 Oct 28 14:26:38 volumio volumio[958]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Feuer, Feuer! (feat. Lina Larissa Strahl)","artist":"Bibi und Tina, Peter Plate, Ulf Leo Sommer, Lina Larissa Strahl","album":"Bibi und Tina: Mädchen gegen Jungs (Der Original-Soundtrack zum Kinofilm)","albumart":"https://i.scdn.co/image/ab67616d00001e02ef840303da8adc7be282090e","uri":"spotify:track:5Ck2bAipFCqcmGc24dlHu7","trackType":"spotify","seek":0,"duration":171,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:26:38 volumio volumio[958]: verbose: CURRENT POSITION 5 Oct 28 14:26:38 volumio volumio[958]: info: CoreStateMachine::syncState stateService play Oct 28 14:26:38 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus stop Oct 28 14:26:38 volumio go-librespot[1202]: time="2024-10-28T14:26:38Z" level=debug msg="fetched chunk 2/13, size: 524288" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:26:39 volumio go-librespot[1202]: time="2024-10-28T14:26:39Z" level=debug msg="fetched chunk 1/13, size: 524288" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:26:39 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:26:39 volumio volumio[958]: SPOTIFY: {"status":"play","service":"spop","title":"Feuer, Feuer! (feat. Lina Larissa Strahl)","artist":"Bibi und Tina, Peter Plate, Ulf Leo Sommer, Lina Larissa Strahl","album":"Bibi und Tina: Mädchen gegen Jungs (Der Original-Soundtrack zum Kinofilm)","albumart":"https://i.scdn.co/image/ab67616d00001e02ef840303da8adc7be282090e","uri":"spotify:track:5Ck2bAipFCqcmGc24dlHu7","trackType":"spotify","seek":0,"duration":171,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:26:39 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:26:39 volumio volumio[958]: info: CorePlayQueue::getTrack 5 Oct 28 14:26:39 volumio volumio[958]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Feuer, Feuer! (feat. Lina Larissa Strahl)","artist":"Bibi und Tina, Peter Plate, Ulf Leo Sommer, Lina Larissa Strahl","album":"Bibi und Tina: Mädchen gegen Jungs (Der Original-Soundtrack zum Kinofilm)","albumart":"https://i.scdn.co/image/ab67616d00001e02ef840303da8adc7be282090e","uri":"spotify:track:5Ck2bAipFCqcmGc24dlHu7","trackType":"spotify","seek":0,"duration":171,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:26:39 volumio volumio[958]: verbose: CURRENT POSITION 5 Oct 28 14:26:39 volumio volumio[958]: info: CoreStateMachine::syncState stateService play Oct 28 14:26:39 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus play Oct 28 14:26:39 volumio volumio[958]: info: Received an update from plugin. extracting info from payload Oct 28 14:26:39 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:26:39 volumio volumio[958]: info: CorePlayQueue::getTrack 5 Oct 28 14:26:39 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 14:26:39 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:26:39 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:26:39 volumio volumio[958]: info: CorePlayQueue::getTrack 5 Oct 28 14:26:39 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:26:44 volumio volumio[958]: info: Preload queue cleared Oct 28 14:26:44 volumio volumio[958]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 28 14:26:44 volumio volumio[958]: info: CoreStateMachine::ClearQueue Oct 28 14:26:44 volumio volumio[958]: info: CoreStateMachine::stop Oct 28 14:26:44 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 14:26:45 volumio volumio[958]: info: CoreStateMachine::stPlaybackTimer Oct 28 14:26:45 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Oct 28 14:26:45 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Oct 28 14:26:45 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:26:45 volumio volumio[958]: info: CorePlayQueue::getTrack 5 Oct 28 14:26:45 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 14:26:45 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:26:45 volumio volumio[958]: info: CoreStateMachine::serviceStop Oct 28 14:26:45 volumio volumio[958]: info: CorePlayQueue::getTrack 5 Oct 28 14:26:45 volumio volumio[958]: info: CoreCommandRouter::serviceStop Oct 28 14:26:45 volumio volumio[958]: info: Spotify Stop Oct 28 14:26:45 volumio volumio[958]: SPOTIFY: SPOTIFY STOP Oct 28 14:26:45 volumio volumio[958]: SPOTIFY: {"status":"play","position":5,"title":"Feuer, Feuer! (feat. Lina Larissa Strahl)","artist":"Bibi und Tina","album":"Bibi und Tina: Mädchen gegen Jungs (Der Original-Soundtrack zum Kinofilm)","albumart":"https://i.scdn.co/image/ab67616d0000b273ef840303da8adc7be282090e","uri":"spotify:track:5Ck2bAipFCqcmGc24dlHu7","trackType":"spotify","codec":"ogg","seek":0,"duration":171,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":null,"repeatSingle":false,"consume":false,"volume":"","dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Oct 28 14:26:45 volumio volumio[958]: info: Sending Spotify command to local API: /player/pause Oct 28 14:26:45 volumio volumio[958]: info: CorePlayQueue::clearPlayQueue Oct 28 14:26:45 volumio volumio[958]: info: CorePlayQueue::saveQueue Oct 28 14:26:45 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue Oct 28 14:26:45 volumio volumio[958]: info: CoreStateMachine::addQueueItems Oct 28 14:26:45 volumio volumio[958]: info: CorePlayQueue::addQueueItems Oct 28 14:26:45 volumio volumio[958]: info: Preload queue cleared Oct 28 14:26:45 volumio volumio[958]: info: Adding Item to queue: spotify:track:6Obb1FCQLZrVRvzXWdgDma Oct 28 14:26:45 volumio volumio[958]: info: Using cached record of: spotify:track:6Obb1FCQLZrVRvzXWdgDma Oct 28 14:26:45 volumio volumio[958]: info: Adding Item to queue: spotify:track:3bDUHKloYp3LlAUXJTI4O4 Oct 28 14:26:45 volumio volumio[958]: info: Using cached record of: spotify:track:3bDUHKloYp3LlAUXJTI4O4 Oct 28 14:26:45 volumio volumio[958]: info: Adding Item to queue: spotify:track:05QrFuWM7KDohFMmXzLOsL Oct 28 14:26:45 volumio volumio[958]: info: Using cached record of: spotify:track:05QrFuWM7KDohFMmXzLOsL Oct 28 14:26:45 volumio volumio[958]: info: Adding Item to queue: spotify:track:3BRSgDlShzyigvcKnB3L0c Oct 28 14:26:45 volumio volumio[958]: info: Using cached record of: spotify:track:3BRSgDlShzyigvcKnB3L0c Oct 28 14:26:45 volumio volumio[958]: info: Adding Item to queue: spotify:track:3pIG1sxniqvPXGcp2Tgky0 Oct 28 14:26:45 volumio volumio[958]: info: Using cached record of: spotify:track:3pIG1sxniqvPXGcp2Tgky0 Oct 28 14:26:45 volumio volumio[958]: info: Adding Item to queue: spotify:track:5Ck2bAipFCqcmGc24dlHu7 Oct 28 14:26:45 volumio volumio[958]: info: Using cached record of: spotify:track:5Ck2bAipFCqcmGc24dlHu7 Oct 28 14:26:45 volumio volumio[958]: info: Adding Item to queue: spotify:track:6pxza2NYAMgI5Ngh0uvmy3 Oct 28 14:26:45 volumio volumio[958]: info: Using cached record of: spotify:track:6pxza2NYAMgI5Ngh0uvmy3 Oct 28 14:26:45 volumio volumio[958]: info: Adding Item to queue: spotify:track:6RfGi5YVgwdlqxwlpq95sQ Oct 28 14:26:45 volumio volumio[958]: info: Using cached record of: spotify:track:6RfGi5YVgwdlqxwlpq95sQ Oct 28 14:26:45 volumio volumio[958]: info: Adding Item to queue: spotify:track:5JGTcHUa3aBI6PUPVP2K5f Oct 28 14:26:45 volumio volumio[958]: info: Using cached record of: spotify:track:5JGTcHUa3aBI6PUPVP2K5f Oct 28 14:26:45 volumio volumio[958]: info: Adding Item to queue: spotify:track:1oClfMl07OFOUdccV0tV17 Oct 28 14:26:45 volumio volumio[958]: info: Using cached record of: spotify:track:1oClfMl07OFOUdccV0tV17 Oct 28 14:26:45 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue Oct 28 14:26:45 volumio volumio[958]: info: CorePlayQueue::saveQueue Oct 28 14:26:45 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Oct 28 14:26:45 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Oct 28 14:26:45 volumio volumio[958]: info: CoreCommandRouter::volumioPlay Oct 28 14:26:45 volumio volumio[958]: info: CoreStateMachine::play index 9 Oct 28 14:26:45 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 14:26:45 volumio volumio[958]: info: CoreStateMachine::stop Oct 28 14:26:45 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 14:26:45 volumio volumio[958]: info: CoreStateMachine::play index undefined Oct 28 14:26:45 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 14:26:45 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:26:45 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer Oct 28 14:26:45 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:26:45 volumio volumio[958]: info: [1730125605064] ControllerSpotify::clearAddPlayTrack Oct 28 14:26:45 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play Oct 28 14:26:45 volumio go-librespot[1202]: time="2024-10-28T14:26:45Z" level=debug msg="pause track at 6670ms" Oct 28 14:26:45 volumio volumio[958]: info: touch_display: Setting screensaver timeout to 120 seconds. Oct 28 14:26:45 volumio go-librespot[1202]: time="2024-10-28T14:26:45Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:26:45 volumio go-librespot[1202]: time="2024-10-28T14:26:45Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:26:45 volumio go-librespot[1202]: time="2024-10-28T14:26:45Z" level=trace msg="emitting websocket event: paused" Oct 28 14:26:45 volumio volumio[958]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5Ck2bAipFCqcmGc24dlHu7","play_origin":"go-librespot"}} Oct 28 14:26:45 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:26:45 volumio volumio[958]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:26:45 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:26:45 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:26:45 volumio volumio[958]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:26:45 volumio volumio[958]: verbose: CURRENT POSITION 9 Oct 28 14:26:45 volumio volumio[958]: info: CoreStateMachine::syncState stateService pause Oct 28 14:26:45 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus stop Oct 28 14:26:45 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:26:45 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:26:45 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 14:26:45 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:26:45 volumio go-librespot[1202]: time="2024-10-28T14:26:45Z" level=debug msg="resolved context of track" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:26:45 volumio go-librespot[1202]: time="2024-10-28T14:26:45Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:26:45 volumio go-librespot[1202]: time="2024-10-28T14:26:45Z" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:26:45 volumio go-librespot[1202]: time="2024-10-28T14:26:45Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:26:45 volumio go-librespot[1202]: time="2024-10-28T14:26:45Z" level=trace msg="emitting websocket event: will_play" Oct 28 14:26:45 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1oClfMl07OFOUdccV0tV17","play_origin":"go-librespot"}} Oct 28 14:26:45 volumio go-librespot[1202]: time="2024-10-28T14:26:45Z" level=debug msg="selected format OGG_VORBIS_320 (9460e85ae59bba46fb4ee07fbd813cb60c2e9ca1)" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:26:45 volumio go-librespot[1202]: time="2024-10-28T14:26:45Z" level=debug msg="requested aes key for file 9460e85ae59bba46fb4ee07fbd813cb60c2e9ca1, gid: 1oClfMl07OFOUdccV0tV17" Oct 28 14:26:46 volumio go-librespot[1202]: time="2024-10-28T14:26:46Z" level=debug msg="fetched first chunk of 16, total size is 8356885 bytes" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:26:46 volumio go-librespot[1202]: time="2024-10-28T14:26:46Z" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Oct 28 14:26:46 volumio go-librespot[1202]: time="2024-10-28T14:26:46Z" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:26:46 volumio go-librespot[1202]: time="2024-10-28T14:26:46Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Oct 28 14:26:46 volumio go-librespot[1202]: time="2024-10-28T14:26:46Z" level=info msg="loaded track \"Kapitel 04: Das Grusellabyrinth (Folge 116)\" (paused: false, position: 0ms, duration: 183429ms, prefetched: false)" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:26:46 volumio go-librespot[1202]: time="2024-10-28T14:26:46Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:26:46 volumio go-librespot[1202]: time="2024-10-28T14:26:46Z" level=trace msg="scheduling prefetch in 153s" Oct 28 14:26:46 volumio go-librespot[1202]: time="2024-10-28T14:26:46Z" level=trace msg="emitting websocket event: metadata" Oct 28 14:26:46 volumio volumio[958]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1oClfMl07OFOUdccV0tV17","name":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist_names":["Bibi und Tina"],"album_name":"Folge 116: Das Grusellabyrinth","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","position":0,"duration":183429,"release_date":"year:2024 month:10 day:18","track_number":6,"disc_number":1}} Oct 28 14:26:46 volumio go-librespot[1202]: time="2024-10-28T14:26:46Z" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:26:46 volumio go-librespot[1202]: time="2024-10-28T14:26:46Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:26:46 volumio go-librespot[1202]: time="2024-10-28T14:26:46Z" level=trace msg="emitting websocket event: playing" Oct 28 14:26:46 volumio volumio[958]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1oClfMl07OFOUdccV0tV17","play_origin":"go-librespot"}} Oct 28 14:26:46 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:26:46 volumio volumio[958]: SPOTIFY: {"status":"play","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:26:46 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:26:46 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:26:46 volumio volumio[958]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:26:46 volumio volumio[958]: verbose: CURRENT POSITION 9 Oct 28 14:26:46 volumio volumio[958]: info: CoreStateMachine::syncState stateService play Oct 28 14:26:46 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus stop Oct 28 14:26:46 volumio go-librespot[1202]: time="2024-10-28T14:26:46Z" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:26:47 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:26:47 volumio volumio[958]: SPOTIFY: {"status":"play","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:26:47 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:26:47 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:26:47 volumio volumio[958]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:26:47 volumio volumio[958]: verbose: CURRENT POSITION 9 Oct 28 14:26:47 volumio volumio[958]: info: CoreStateMachine::syncState stateService play Oct 28 14:26:47 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus play Oct 28 14:26:47 volumio volumio[958]: info: Received an update from plugin. extracting info from payload Oct 28 14:26:47 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:26:47 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:26:47 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 14:26:47 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:26:47 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:26:47 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:26:47 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:26:47 volumio go-librespot[1202]: time="2024-10-28T14:26:47Z" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:26:52 volumio kernel: hwmon hwmon1: Voltage normalised Oct 28 14:26:57 volumio go-librespot[1202]: time="2024-10-28T14:26:57Z" level=debug msg="fetched chunk 4/15, size: 524288" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:26:58 volumio kernel: hwmon hwmon1: Undervoltage detected! Oct 28 14:27:02 volumio kernel: hwmon hwmon1: Voltage normalised Oct 28 14:27:08 volumio go-librespot[1202]: time="2024-10-28T14:27:08Z" level=debug msg="fetched chunk 5/15, size: 524288" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:19 volumio go-librespot[1202]: time="2024-10-28T14:27:19Z" level=debug msg="fetched chunk 6/15, size: 524288" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:28 volumio volumio[958]: info: CoreCommandRouter::volumioPrevious Oct 28 14:27:28 volumio volumio[958]: info: CoreStateMachine::previous Oct 28 14:27:28 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:28 volumio volumio[958]: info: Spotify seek to: 0 Oct 28 14:27:28 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/seek Oct 28 14:27:28 volumio go-librespot[1202]: time="2024-10-28T14:27:28Z" level=debug msg="seek track to 0ms" Oct 28 14:27:28 volumio go-librespot[1202]: time="2024-10-28T14:27:28Z" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:28 volumio go-librespot[1202]: time="2024-10-28T14:27:28Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:28 volumio go-librespot[1202]: time="2024-10-28T14:27:28Z" level=trace msg="scheduling prefetch in 153s" Oct 28 14:27:28 volumio go-librespot[1202]: time="2024-10-28T14:27:28Z" level=trace msg="emitting websocket event: seek" Oct 28 14:27:28 volumio volumio[958]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:1oClfMl07OFOUdccV0tV17","position":0,"duration":183429,"play_origin":"go-librespot"}} Oct 28 14:27:28 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:27:28 volumio volumio[958]: SPOTIFY: {"status":"play","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:28 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:27:28 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:28 volumio volumio[958]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:28 volumio volumio[958]: verbose: CURRENT POSITION 9 Oct 28 14:27:28 volumio volumio[958]: info: CoreStateMachine::syncState stateService play Oct 28 14:27:28 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus play Oct 28 14:27:28 volumio volumio[958]: info: Received an update from plugin. extracting info from payload Oct 28 14:27:28 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:28 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:28 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:28 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:28 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:28 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:29 volumio volumio[958]: info: CoreCommandRouter::volumioPrevious Oct 28 14:27:29 volumio volumio[958]: info: CoreStateMachine::previous Oct 28 14:27:29 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:29 volumio volumio[958]: info: CoreStateMachine::stop Oct 28 14:27:29 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 14:27:29 volumio volumio[958]: info: CoreStateMachine::stPlaybackTimer Oct 28 14:27:29 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Oct 28 14:27:29 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Oct 28 14:27:29 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:29 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:29 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 14:27:29 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:29 volumio volumio[958]: info: CoreStateMachine::serviceStop Oct 28 14:27:29 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:29 volumio volumio[958]: info: CoreCommandRouter::serviceStop Oct 28 14:27:29 volumio volumio[958]: info: Spotify Stop Oct 28 14:27:29 volumio volumio[958]: SPOTIFY: SPOTIFY STOP Oct 28 14:27:29 volumio volumio[958]: SPOTIFY: {"status":"play","position":9,"title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d0000b273fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","codec":"ogg","seek":0,"duration":183,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":null,"repeatSingle":false,"consume":false,"volume":"","dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Oct 28 14:27:29 volumio volumio[958]: info: Sending Spotify command to local API: /player/pause Oct 28 14:27:29 volumio go-librespot[1202]: time="2024-10-28T14:27:29Z" level=debug msg="pause track at 1454ms" Oct 28 14:27:29 volumio volumio[958]: info: touch_display: Setting screensaver timeout to 120 seconds. Oct 28 14:27:29 volumio go-librespot[1202]: time="2024-10-28T14:27:29Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:29 volumio go-librespot[1202]: time="2024-10-28T14:27:29Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:29 volumio go-librespot[1202]: time="2024-10-28T14:27:29Z" level=trace msg="emitting websocket event: paused" Oct 28 14:27:29 volumio volumio[958]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:1oClfMl07OFOUdccV0tV17","play_origin":"go-librespot"}} Oct 28 14:27:29 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:27:29 volumio volumio[958]: SPOTIFY: {"status":"pause","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":1000,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:29 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:27:29 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:29 volumio volumio[958]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":1000,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:29 volumio volumio[958]: verbose: CURRENT POSITION 9 Oct 28 14:27:29 volumio volumio[958]: info: CoreStateMachine::syncState stateService pause Oct 28 14:27:29 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus stop Oct 28 14:27:29 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:29 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:29 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 14:27:29 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:29 volumio volumio[958]: info: CoreStateMachine::play index undefined Oct 28 14:27:29 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 14:27:29 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:29 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer Oct 28 14:27:29 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:29 volumio volumio[958]: info: [1730125649954] ControllerSpotify::clearAddPlayTrack Oct 28 14:27:29 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play Oct 28 14:27:29 volumio go-librespot[1202]: time="2024-10-28T14:27:29Z" level=debug msg="resolved context of track" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:29 volumio go-librespot[1202]: time="2024-10-28T14:27:29Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:29 volumio go-librespot[1202]: time="2024-10-28T14:27:29Z" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:30 volumio go-librespot[1202]: time="2024-10-28T14:27:30Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:30 volumio go-librespot[1202]: time="2024-10-28T14:27:30Z" level=trace msg="emitting websocket event: will_play" Oct 28 14:27:30 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1oClfMl07OFOUdccV0tV17","play_origin":"go-librespot"}} Oct 28 14:27:30 volumio go-librespot[1202]: time="2024-10-28T14:27:30Z" level=debug msg="selected format OGG_VORBIS_320 (9460e85ae59bba46fb4ee07fbd813cb60c2e9ca1)" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:30 volumio go-librespot[1202]: time="2024-10-28T14:27:30Z" level=debug msg="requested aes key for file 9460e85ae59bba46fb4ee07fbd813cb60c2e9ca1, gid: 1oClfMl07OFOUdccV0tV17" Oct 28 14:27:30 volumio go-librespot[1202]: time="2024-10-28T14:27:30Z" level=debug msg="fetched first chunk of 16, total size is 8356885 bytes" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:30 volumio go-librespot[1202]: time="2024-10-28T14:27:30Z" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Oct 28 14:27:30 volumio go-librespot[1202]: time="2024-10-28T14:27:30Z" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:30 volumio go-librespot[1202]: time="2024-10-28T14:27:30Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Oct 28 14:27:30 volumio go-librespot[1202]: time="2024-10-28T14:27:30Z" level=info msg="loaded track \"Kapitel 04: Das Grusellabyrinth (Folge 116)\" (paused: false, position: 0ms, duration: 183429ms, prefetched: false)" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:31 volumio go-librespot[1202]: time="2024-10-28T14:27:31Z" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:31 volumio go-librespot[1202]: time="2024-10-28T14:27:31Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:31 volumio go-librespot[1202]: time="2024-10-28T14:27:31Z" level=trace msg="scheduling prefetch in 153s" Oct 28 14:27:31 volumio go-librespot[1202]: time="2024-10-28T14:27:31Z" level=trace msg="emitting websocket event: metadata" Oct 28 14:27:31 volumio volumio[958]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1oClfMl07OFOUdccV0tV17","name":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist_names":["Bibi und Tina"],"album_name":"Folge 116: Das Grusellabyrinth","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","position":0,"duration":183429,"release_date":"year:2024 month:10 day:18","track_number":6,"disc_number":1}} Oct 28 14:27:31 volumio go-librespot[1202]: time="2024-10-28T14:27:31Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:31 volumio go-librespot[1202]: time="2024-10-28T14:27:31Z" level=trace msg="emitting websocket event: playing" Oct 28 14:27:31 volumio volumio[958]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1oClfMl07OFOUdccV0tV17","play_origin":"go-librespot"}} Oct 28 14:27:31 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:27:31 volumio volumio[958]: SPOTIFY: {"status":"play","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:31 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:27:31 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:31 volumio volumio[958]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:31 volumio volumio[958]: verbose: CURRENT POSITION 9 Oct 28 14:27:31 volumio volumio[958]: info: CoreStateMachine::syncState stateService play Oct 28 14:27:31 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus stop Oct 28 14:27:31 volumio go-librespot[1202]: time="2024-10-28T14:27:31Z" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:31 volumio go-librespot[1202]: time="2024-10-28T14:27:31Z" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:31 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:27:31 volumio volumio[958]: SPOTIFY: {"status":"play","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:31 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:27:31 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:31 volumio volumio[958]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:31 volumio volumio[958]: verbose: CURRENT POSITION 9 Oct 28 14:27:31 volumio volumio[958]: info: CoreStateMachine::syncState stateService play Oct 28 14:27:31 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus play Oct 28 14:27:31 volumio volumio[958]: info: Received an update from plugin. extracting info from payload Oct 28 14:27:31 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:31 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:31 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 14:27:31 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:31 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:31 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:31 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:31 volumio volumio[958]: info: CoreCommandRouter::volumioPrevious Oct 28 14:27:31 volumio volumio[958]: info: CoreStateMachine::previous Oct 28 14:27:31 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:31 volumio volumio[958]: info: Spotify seek to: 0 Oct 28 14:27:31 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/seek Oct 28 14:27:31 volumio go-librespot[1202]: time="2024-10-28T14:27:31Z" level=debug msg="seek track to 0ms" Oct 28 14:27:31 volumio go-librespot[1202]: time="2024-10-28T14:27:31Z" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:32 volumio go-librespot[1202]: time="2024-10-28T14:27:32Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:32 volumio go-librespot[1202]: time="2024-10-28T14:27:32Z" level=trace msg="scheduling prefetch in 153s" Oct 28 14:27:32 volumio go-librespot[1202]: time="2024-10-28T14:27:32Z" level=trace msg="emitting websocket event: seek" Oct 28 14:27:32 volumio volumio[958]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:1oClfMl07OFOUdccV0tV17","position":0,"duration":183429,"play_origin":"go-librespot"}} Oct 28 14:27:32 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:27:32 volumio volumio[958]: SPOTIFY: {"status":"play","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:32 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:27:32 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:32 volumio volumio[958]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:32 volumio volumio[958]: verbose: CURRENT POSITION 9 Oct 28 14:27:32 volumio volumio[958]: info: CoreStateMachine::syncState stateService play Oct 28 14:27:32 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus play Oct 28 14:27:32 volumio volumio[958]: info: Received an update from plugin. extracting info from payload Oct 28 14:27:32 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:32 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:32 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:32 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:32 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:32 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:32 volumio volumio[958]: info: CoreCommandRouter::volumioPrevious Oct 28 14:27:32 volumio volumio[958]: info: CoreStateMachine::previous Oct 28 14:27:32 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:32 volumio volumio[958]: info: CoreStateMachine::stop Oct 28 14:27:32 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 14:27:32 volumio volumio[958]: info: CoreStateMachine::stPlaybackTimer Oct 28 14:27:32 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Oct 28 14:27:32 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Oct 28 14:27:32 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:32 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:32 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 14:27:32 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:32 volumio volumio[958]: info: CoreStateMachine::serviceStop Oct 28 14:27:32 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:32 volumio volumio[958]: info: CoreCommandRouter::serviceStop Oct 28 14:27:32 volumio volumio[958]: info: Spotify Stop Oct 28 14:27:32 volumio volumio[958]: SPOTIFY: SPOTIFY STOP Oct 28 14:27:32 volumio volumio[958]: SPOTIFY: {"status":"play","position":9,"title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d0000b273fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","codec":"ogg","seek":0,"duration":183,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":null,"repeatSingle":false,"consume":false,"volume":"","dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Oct 28 14:27:32 volumio volumio[958]: info: Sending Spotify command to local API: /player/pause Oct 28 14:27:32 volumio go-librespot[1202]: time="2024-10-28T14:27:32Z" level=debug msg="pause track at 551ms" Oct 28 14:27:32 volumio volumio[958]: info: touch_display: Setting screensaver timeout to 120 seconds. Oct 28 14:27:32 volumio go-librespot[1202]: time="2024-10-28T14:27:32Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:32 volumio go-librespot[1202]: time="2024-10-28T14:27:32Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:32 volumio go-librespot[1202]: time="2024-10-28T14:27:32Z" level=trace msg="emitting websocket event: paused" Oct 28 14:27:32 volumio volumio[958]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:1oClfMl07OFOUdccV0tV17","play_origin":"go-librespot"}} Oct 28 14:27:32 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:27:32 volumio volumio[958]: SPOTIFY: {"status":"pause","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":1000,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:32 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:27:32 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:32 volumio volumio[958]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":1000,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:32 volumio volumio[958]: verbose: CURRENT POSITION 9 Oct 28 14:27:32 volumio volumio[958]: info: CoreStateMachine::syncState stateService pause Oct 28 14:27:32 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus stop Oct 28 14:27:32 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:32 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:32 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 14:27:32 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:32 volumio volumio[958]: info: CoreStateMachine::play index undefined Oct 28 14:27:32 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 14:27:32 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:32 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer Oct 28 14:27:32 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:32 volumio volumio[958]: info: [1730125652855] ControllerSpotify::clearAddPlayTrack Oct 28 14:27:32 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play Oct 28 14:27:32 volumio go-librespot[1202]: time="2024-10-28T14:27:32Z" level=debug msg="resolved context of track" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:32 volumio go-librespot[1202]: time="2024-10-28T14:27:32Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:32 volumio go-librespot[1202]: time="2024-10-28T14:27:32Z" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:32 volumio go-librespot[1202]: time="2024-10-28T14:27:32Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:32 volumio go-librespot[1202]: time="2024-10-28T14:27:32Z" level=trace msg="emitting websocket event: will_play" Oct 28 14:27:32 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1oClfMl07OFOUdccV0tV17","play_origin":"go-librespot"}} Oct 28 14:27:33 volumio go-librespot[1202]: time="2024-10-28T14:27:33Z" level=debug msg="selected format OGG_VORBIS_320 (9460e85ae59bba46fb4ee07fbd813cb60c2e9ca1)" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:33 volumio go-librespot[1202]: time="2024-10-28T14:27:33Z" level=debug msg="requested aes key for file 9460e85ae59bba46fb4ee07fbd813cb60c2e9ca1, gid: 1oClfMl07OFOUdccV0tV17" Oct 28 14:27:33 volumio go-librespot[1202]: time="2024-10-28T14:27:33Z" level=debug msg="fetched first chunk of 16, total size is 8356885 bytes" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:33 volumio go-librespot[1202]: time="2024-10-28T14:27:33Z" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Oct 28 14:27:33 volumio go-librespot[1202]: time="2024-10-28T14:27:33Z" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:33 volumio go-librespot[1202]: time="2024-10-28T14:27:33Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Oct 28 14:27:33 volumio go-librespot[1202]: time="2024-10-28T14:27:33Z" level=info msg="loaded track \"Kapitel 04: Das Grusellabyrinth (Folge 116)\" (paused: false, position: 0ms, duration: 183429ms, prefetched: false)" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:33 volumio go-librespot[1202]: time="2024-10-28T14:27:33Z" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:33 volumio go-librespot[1202]: time="2024-10-28T14:27:33Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:33 volumio go-librespot[1202]: time="2024-10-28T14:27:33Z" level=trace msg="scheduling prefetch in 153s" Oct 28 14:27:33 volumio go-librespot[1202]: time="2024-10-28T14:27:33Z" level=trace msg="emitting websocket event: metadata" Oct 28 14:27:33 volumio volumio[958]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1oClfMl07OFOUdccV0tV17","name":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist_names":["Bibi und Tina"],"album_name":"Folge 116: Das Grusellabyrinth","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","position":0,"duration":183429,"release_date":"year:2024 month:10 day:18","track_number":6,"disc_number":1}} Oct 28 14:27:33 volumio go-librespot[1202]: time="2024-10-28T14:27:33Z" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:33 volumio go-librespot[1202]: time="2024-10-28T14:27:33Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:33 volumio go-librespot[1202]: time="2024-10-28T14:27:33Z" level=trace msg="emitting websocket event: playing" Oct 28 14:27:34 volumio volumio[958]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1oClfMl07OFOUdccV0tV17","play_origin":"go-librespot"}} Oct 28 14:27:34 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:27:34 volumio volumio[958]: SPOTIFY: {"status":"play","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:34 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:27:34 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:34 volumio volumio[958]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:34 volumio volumio[958]: verbose: CURRENT POSITION 9 Oct 28 14:27:34 volumio volumio[958]: info: CoreStateMachine::syncState stateService play Oct 28 14:27:34 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus stop Oct 28 14:27:34 volumio go-librespot[1202]: time="2024-10-28T14:27:34Z" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:1oClfMl07OFOUdccV0tV17" Oct 28 14:27:34 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:27:34 volumio volumio[958]: SPOTIFY: {"status":"play","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:34 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:27:34 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:34 volumio volumio[958]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d00001e02fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:34 volumio volumio[958]: verbose: CURRENT POSITION 9 Oct 28 14:27:34 volumio volumio[958]: info: CoreStateMachine::syncState stateService play Oct 28 14:27:34 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus play Oct 28 14:27:34 volumio volumio[958]: info: Received an update from plugin. extracting info from payload Oct 28 14:27:34 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:34 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:34 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 14:27:34 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:34 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:34 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:34 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:35 volumio kernel: hwmon hwmon1: Undervoltage detected! Oct 28 14:27:36 volumio volumio[958]: info: CoreCommandRouter::volumioNext Oct 28 14:27:36 volumio volumio[958]: info: CoreStateMachine::next Oct 28 14:27:36 volumio volumio[958]: info: CoreStateMachine::stop Oct 28 14:27:36 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 14:27:36 volumio volumio[958]: info: CoreStateMachine::stPlaybackTimer Oct 28 14:27:36 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Oct 28 14:27:36 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Oct 28 14:27:36 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:36 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:36 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 14:27:36 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:36 volumio volumio[958]: info: CoreStateMachine::serviceStop Oct 28 14:27:36 volumio volumio[958]: info: CorePlayQueue::getTrack 9 Oct 28 14:27:36 volumio volumio[958]: info: CoreCommandRouter::serviceStop Oct 28 14:27:36 volumio volumio[958]: info: Spotify Stop Oct 28 14:27:36 volumio volumio[958]: SPOTIFY: SPOTIFY STOP Oct 28 14:27:36 volumio volumio[958]: SPOTIFY: {"status":"play","position":9,"title":"Kapitel 04: Das Grusellabyrinth (Folge 116)","artist":"Bibi und Tina","album":"Folge 116: Das Grusellabyrinth","albumart":"https://i.scdn.co/image/ab67616d0000b273fed9b8c3641e3c7b70863eda","uri":"spotify:track:1oClfMl07OFOUdccV0tV17","trackType":"spotify","codec":"ogg","seek":0,"duration":183,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":null,"repeatSingle":false,"consume":false,"volume":"","dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Oct 28 14:27:36 volumio volumio[958]: info: Sending Spotify command to local API: /player/pause Oct 28 14:27:36 volumio volumio[958]: info: CoreStateMachine::play index undefined Oct 28 14:27:36 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 14:27:36 volumio volumio[958]: info: CorePlayQueue::getTrack 7 Oct 28 14:27:36 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer Oct 28 14:27:36 volumio volumio[958]: info: CorePlayQueue::getTrack 7 Oct 28 14:27:36 volumio volumio[958]: info: [1730125656439] ControllerSpotify::clearAddPlayTrack Oct 28 14:27:36 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play Oct 28 14:27:36 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Oct 28 14:27:36 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Oct 28 14:27:36 volumio go-librespot[1202]: time="2024-10-28T14:27:36Z" level=debug msg="pause track at 2888ms" Oct 28 14:27:36 volumio volumio[958]: info: touch_display: Setting screensaver timeout to 120 seconds. Oct 28 14:27:36 volumio go-librespot[1202]: time="2024-10-28T14:27:36Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:36 volumio go-librespot[1202]: time="2024-10-28T14:27:36Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:36 volumio go-librespot[1202]: time="2024-10-28T14:27:36Z" level=trace msg="emitting websocket event: paused" Oct 28 14:27:36 volumio volumio[958]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:1oClfMl07OFOUdccV0tV17","play_origin":"go-librespot"}} Oct 28 14:27:36 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:27:36 volumio volumio[958]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:36 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:27:36 volumio volumio[958]: info: CorePlayQueue::getTrack 7 Oct 28 14:27:36 volumio volumio[958]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:36 volumio volumio[958]: verbose: CURRENT POSITION 7 Oct 28 14:27:36 volumio volumio[958]: info: CoreStateMachine::syncState stateService pause Oct 28 14:27:36 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus stop Oct 28 14:27:36 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:36 volumio volumio[958]: info: CorePlayQueue::getTrack 7 Oct 28 14:27:36 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 14:27:36 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:36 volumio go-librespot[1202]: time="2024-10-28T14:27:36Z" level=debug msg="resolved context of track" uri="spotify:track:6RfGi5YVgwdlqxwlpq95sQ" Oct 28 14:27:36 volumio go-librespot[1202]: time="2024-10-28T14:27:36Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:6RfGi5YVgwdlqxwlpq95sQ" Oct 28 14:27:36 volumio go-librespot[1202]: time="2024-10-28T14:27:36Z" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:6RfGi5YVgwdlqxwlpq95sQ" Oct 28 14:27:36 volumio go-librespot[1202]: time="2024-10-28T14:27:36Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:36 volumio go-librespot[1202]: time="2024-10-28T14:27:36Z" level=trace msg="emitting websocket event: will_play" Oct 28 14:27:36 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6RfGi5YVgwdlqxwlpq95sQ","play_origin":"go-librespot"}} Oct 28 14:27:36 volumio go-librespot[1202]: time="2024-10-28T14:27:36Z" level=debug msg="selected format OGG_VORBIS_320 (c006ccffd85114ce05fe56d1e0a7031146b86b12)" uri="spotify:track:6RfGi5YVgwdlqxwlpq95sQ" Oct 28 14:27:36 volumio go-librespot[1202]: time="2024-10-28T14:27:36Z" level=debug msg="requested aes key for file c006ccffd85114ce05fe56d1e0a7031146b86b12, gid: 6RfGi5YVgwdlqxwlpq95sQ" Oct 28 14:27:37 volumio go-librespot[1202]: time="2024-10-28T14:27:37Z" level=debug msg="fetched first chunk of 13, total size is 6435276 bytes" uri="spotify:track:6RfGi5YVgwdlqxwlpq95sQ" Oct 28 14:27:37 volumio go-librespot[1202]: time="2024-10-28T14:27:37Z" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:6RfGi5YVgwdlqxwlpq95sQ" Oct 28 14:27:37 volumio go-librespot[1202]: time="2024-10-28T14:27:37Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Oct 28 14:27:37 volumio go-librespot[1202]: time="2024-10-28T14:27:37Z" level=info msg="loaded track \"No Risk, no Fun (feat. Lina Larissa Strahl, Emilio Moutaoukkil)\" (paused: false, position: 0ms, duration: 159172ms, prefetched: false)" uri="spotify:track:6RfGi5YVgwdlqxwlpq95sQ" Oct 28 14:27:37 volumio go-librespot[1202]: time="2024-10-28T14:27:37Z" level=debug msg="fetched chunk 1/12, size: 524288" uri="spotify:track:6RfGi5YVgwdlqxwlpq95sQ" Oct 28 14:27:37 volumio go-librespot[1202]: time="2024-10-28T14:27:37Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:37 volumio go-librespot[1202]: time="2024-10-28T14:27:37Z" level=trace msg="scheduling prefetch in 129s" Oct 28 14:27:37 volumio go-librespot[1202]: time="2024-10-28T14:27:37Z" level=trace msg="emitting websocket event: metadata" Oct 28 14:27:37 volumio volumio[958]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6RfGi5YVgwdlqxwlpq95sQ","name":"No Risk, no Fun (feat. Lina Larissa Strahl, Emilio Moutaoukkil)","artist_names":["Bibi und Tina","Peter Plate","Ulf Leo Sommer","Lina Larissa Strahl","Emilio Moutaoukkil"],"album_name":"Bibi und Tina: VOLL VERHEXT! (Der Original-Soundtrack zum Kinofilm)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e023ebf3820c34e28534dd73501","position":0,"duration":159172,"release_date":"year:2014 month:12 day:19","track_number":2,"disc_number":1}} Oct 28 14:27:37 volumio go-librespot[1202]: time="2024-10-28T14:27:37Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:37 volumio go-librespot[1202]: time="2024-10-28T14:27:37Z" level=trace msg="emitting websocket event: playing" Oct 28 14:27:37 volumio volumio[958]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6RfGi5YVgwdlqxwlpq95sQ","play_origin":"go-librespot"}} Oct 28 14:27:37 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:27:37 volumio volumio[958]: SPOTIFY: {"status":"play","service":"spop","title":"No Risk, no Fun (feat. Lina Larissa Strahl, Emilio Moutaoukkil)","artist":"Bibi und Tina, Peter Plate, Ulf Leo Sommer, Lina Larissa Strahl, Emilio Moutaoukkil","album":"Bibi und Tina: VOLL VERHEXT! (Der Original-Soundtrack zum Kinofilm)","albumart":"https://i.scdn.co/image/ab67616d00001e023ebf3820c34e28534dd73501","uri":"spotify:track:6RfGi5YVgwdlqxwlpq95sQ","trackType":"spotify","seek":0,"duration":159,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:37 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:27:37 volumio volumio[958]: info: CorePlayQueue::getTrack 7 Oct 28 14:27:37 volumio volumio[958]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"No Risk, no Fun (feat. Lina Larissa Strahl, Emilio Moutaoukkil)","artist":"Bibi und Tina, Peter Plate, Ulf Leo Sommer, Lina Larissa Strahl, Emilio Moutaoukkil","album":"Bibi und Tina: VOLL VERHEXT! (Der Original-Soundtrack zum Kinofilm)","albumart":"https://i.scdn.co/image/ab67616d00001e023ebf3820c34e28534dd73501","uri":"spotify:track:6RfGi5YVgwdlqxwlpq95sQ","trackType":"spotify","seek":0,"duration":159,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:37 volumio volumio[958]: verbose: CURRENT POSITION 7 Oct 28 14:27:37 volumio volumio[958]: info: CoreStateMachine::syncState stateService play Oct 28 14:27:37 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus stop Oct 28 14:27:37 volumio go-librespot[1202]: time="2024-10-28T14:27:37Z" level=debug msg="fetched chunk 2/12, size: 524288" uri="spotify:track:6RfGi5YVgwdlqxwlpq95sQ" Oct 28 14:27:38 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:27:38 volumio volumio[958]: SPOTIFY: {"status":"play","service":"spop","title":"No Risk, no Fun (feat. Lina Larissa Strahl, Emilio Moutaoukkil)","artist":"Bibi und Tina, Peter Plate, Ulf Leo Sommer, Lina Larissa Strahl, Emilio Moutaoukkil","album":"Bibi und Tina: VOLL VERHEXT! (Der Original-Soundtrack zum Kinofilm)","albumart":"https://i.scdn.co/image/ab67616d00001e023ebf3820c34e28534dd73501","uri":"spotify:track:6RfGi5YVgwdlqxwlpq95sQ","trackType":"spotify","seek":0,"duration":159,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:38 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:27:38 volumio volumio[958]: info: CorePlayQueue::getTrack 7 Oct 28 14:27:38 volumio volumio[958]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"No Risk, no Fun (feat. Lina Larissa Strahl, Emilio Moutaoukkil)","artist":"Bibi und Tina, Peter Plate, Ulf Leo Sommer, Lina Larissa Strahl, Emilio Moutaoukkil","album":"Bibi und Tina: VOLL VERHEXT! (Der Original-Soundtrack zum Kinofilm)","albumart":"https://i.scdn.co/image/ab67616d00001e023ebf3820c34e28534dd73501","uri":"spotify:track:6RfGi5YVgwdlqxwlpq95sQ","trackType":"spotify","seek":0,"duration":159,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:38 volumio volumio[958]: verbose: CURRENT POSITION 7 Oct 28 14:27:38 volumio volumio[958]: info: CoreStateMachine::syncState stateService play Oct 28 14:27:38 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus play Oct 28 14:27:38 volumio volumio[958]: info: Received an update from plugin. extracting info from payload Oct 28 14:27:38 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:38 volumio volumio[958]: info: CorePlayQueue::getTrack 7 Oct 28 14:27:38 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 14:27:38 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:38 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:38 volumio volumio[958]: info: CorePlayQueue::getTrack 7 Oct 28 14:27:38 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:38 volumio go-librespot[1202]: time="2024-10-28T14:27:38Z" level=debug msg="fetched chunk 3/12, size: 524288" uri="spotify:track:6RfGi5YVgwdlqxwlpq95sQ" Oct 28 14:27:44 volumio kernel: hwmon hwmon1: Voltage normalised Oct 28 14:27:44 volumio volumio[958]: info: CoreCommandRouter::volumioPrevious Oct 28 14:27:44 volumio volumio[958]: info: CoreStateMachine::previous Oct 28 14:27:44 volumio volumio[958]: info: CorePlayQueue::getTrack 7 Oct 28 14:27:44 volumio volumio[958]: info: Spotify seek to: 0 Oct 28 14:27:44 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/seek Oct 28 14:27:44 volumio go-librespot[1202]: time="2024-10-28T14:27:44Z" level=debug msg="seek track to 0ms" Oct 28 14:27:44 volumio go-librespot[1202]: time="2024-10-28T14:27:44Z" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:6RfGi5YVgwdlqxwlpq95sQ" Oct 28 14:27:44 volumio go-librespot[1202]: time="2024-10-28T14:27:44Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:44 volumio go-librespot[1202]: time="2024-10-28T14:27:44Z" level=trace msg="scheduling prefetch in 129s" Oct 28 14:27:44 volumio go-librespot[1202]: time="2024-10-28T14:27:44Z" level=trace msg="emitting websocket event: seek" Oct 28 14:27:44 volumio volumio[958]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:6RfGi5YVgwdlqxwlpq95sQ","position":0,"duration":159172,"play_origin":"go-librespot"}} Oct 28 14:27:44 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:27:44 volumio volumio[958]: SPOTIFY: {"status":"play","service":"spop","title":"No Risk, no Fun (feat. Lina Larissa Strahl, Emilio Moutaoukkil)","artist":"Bibi und Tina, Peter Plate, Ulf Leo Sommer, Lina Larissa Strahl, Emilio Moutaoukkil","album":"Bibi und Tina: VOLL VERHEXT! (Der Original-Soundtrack zum Kinofilm)","albumart":"https://i.scdn.co/image/ab67616d00001e023ebf3820c34e28534dd73501","uri":"spotify:track:6RfGi5YVgwdlqxwlpq95sQ","trackType":"spotify","seek":0,"duration":159,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:44 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:27:44 volumio volumio[958]: info: CorePlayQueue::getTrack 7 Oct 28 14:27:44 volumio volumio[958]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"No Risk, no Fun (feat. Lina Larissa Strahl, Emilio Moutaoukkil)","artist":"Bibi und Tina, Peter Plate, Ulf Leo Sommer, Lina Larissa Strahl, Emilio Moutaoukkil","album":"Bibi und Tina: VOLL VERHEXT! (Der Original-Soundtrack zum Kinofilm)","albumart":"https://i.scdn.co/image/ab67616d00001e023ebf3820c34e28534dd73501","uri":"spotify:track:6RfGi5YVgwdlqxwlpq95sQ","trackType":"spotify","seek":0,"duration":159,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:44 volumio volumio[958]: verbose: CURRENT POSITION 7 Oct 28 14:27:44 volumio volumio[958]: info: CoreStateMachine::syncState stateService play Oct 28 14:27:44 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus play Oct 28 14:27:44 volumio volumio[958]: info: Received an update from plugin. extracting info from payload Oct 28 14:27:44 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:44 volumio volumio[958]: info: CorePlayQueue::getTrack 7 Oct 28 14:27:44 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:44 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:44 volumio volumio[958]: info: CorePlayQueue::getTrack 7 Oct 28 14:27:44 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:46 volumio volumio[958]: info: CoreCommandRouter::volumioPrevious Oct 28 14:27:46 volumio volumio[958]: info: CoreStateMachine::previous Oct 28 14:27:46 volumio volumio[958]: info: CorePlayQueue::getTrack 7 Oct 28 14:27:46 volumio volumio[958]: info: CoreStateMachine::stop Oct 28 14:27:46 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 14:27:46 volumio volumio[958]: info: CoreStateMachine::stPlaybackTimer Oct 28 14:27:46 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Oct 28 14:27:46 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Oct 28 14:27:46 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:46 volumio volumio[958]: info: CorePlayQueue::getTrack 7 Oct 28 14:27:46 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 14:27:46 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:46 volumio volumio[958]: info: CoreStateMachine::serviceStop Oct 28 14:27:46 volumio volumio[958]: info: CorePlayQueue::getTrack 7 Oct 28 14:27:46 volumio volumio[958]: info: CoreCommandRouter::serviceStop Oct 28 14:27:46 volumio volumio[958]: info: Spotify Stop Oct 28 14:27:46 volumio volumio[958]: SPOTIFY: SPOTIFY STOP Oct 28 14:27:46 volumio volumio[958]: SPOTIFY: {"status":"play","position":7,"title":"No Risk, no Fun (feat. Lina Larissa Strahl, Emilio Moutaoukkil)","artist":"Bibi und Tina","album":"Bibi und Tina: VOLL VERHEXT! (Der Original-Soundtrack zum Kinofilm)","albumart":"https://i.scdn.co/image/ab67616d0000b2733ebf3820c34e28534dd73501","uri":"spotify:track:6RfGi5YVgwdlqxwlpq95sQ","trackType":"spotify","codec":"ogg","seek":0,"duration":159,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":null,"repeatSingle":false,"consume":false,"volume":"","dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Oct 28 14:27:46 volumio volumio[958]: info: Sending Spotify command to local API: /player/pause Oct 28 14:27:46 volumio go-librespot[1202]: time="2024-10-28T14:27:46Z" level=debug msg="pause track at 2033ms" Oct 28 14:27:46 volumio volumio[958]: info: touch_display: Setting screensaver timeout to 120 seconds. Oct 28 14:27:46 volumio go-librespot[1202]: time="2024-10-28T14:27:46Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:46 volumio go-librespot[1202]: time="2024-10-28T14:27:46Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:46 volumio go-librespot[1202]: time="2024-10-28T14:27:46Z" level=trace msg="emitting websocket event: paused" Oct 28 14:27:46 volumio volumio[958]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:6RfGi5YVgwdlqxwlpq95sQ","play_origin":"go-librespot"}} Oct 28 14:27:46 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:27:46 volumio volumio[958]: SPOTIFY: {"status":"pause","service":"spop","title":"No Risk, no Fun (feat. Lina Larissa Strahl, Emilio Moutaoukkil)","artist":"Bibi und Tina, Peter Plate, Ulf Leo Sommer, Lina Larissa Strahl, Emilio Moutaoukkil","album":"Bibi und Tina: VOLL VERHEXT! (Der Original-Soundtrack zum Kinofilm)","albumart":"https://i.scdn.co/image/ab67616d00001e023ebf3820c34e28534dd73501","uri":"spotify:track:6RfGi5YVgwdlqxwlpq95sQ","trackType":"spotify","seek":3000,"duration":159,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:46 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:27:46 volumio volumio[958]: info: CorePlayQueue::getTrack 7 Oct 28 14:27:46 volumio volumio[958]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"No Risk, no Fun (feat. Lina Larissa Strahl, Emilio Moutaoukkil)","artist":"Bibi und Tina, Peter Plate, Ulf Leo Sommer, Lina Larissa Strahl, Emilio Moutaoukkil","album":"Bibi und Tina: VOLL VERHEXT! (Der Original-Soundtrack zum Kinofilm)","albumart":"https://i.scdn.co/image/ab67616d00001e023ebf3820c34e28534dd73501","uri":"spotify:track:6RfGi5YVgwdlqxwlpq95sQ","trackType":"spotify","seek":3000,"duration":159,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:46 volumio volumio[958]: verbose: CURRENT POSITION 7 Oct 28 14:27:46 volumio volumio[958]: info: CoreStateMachine::syncState stateService pause Oct 28 14:27:46 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus stop Oct 28 14:27:46 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:46 volumio volumio[958]: info: CorePlayQueue::getTrack 7 Oct 28 14:27:46 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 14:27:46 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:47 volumio volumio[958]: info: CoreStateMachine::play index undefined Oct 28 14:27:47 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 14:27:47 volumio volumio[958]: info: CorePlayQueue::getTrack 5 Oct 28 14:27:47 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer Oct 28 14:27:47 volumio volumio[958]: info: CorePlayQueue::getTrack 5 Oct 28 14:27:47 volumio volumio[958]: info: [1730125667198] ControllerSpotify::clearAddPlayTrack Oct 28 14:27:47 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play Oct 28 14:27:47 volumio go-librespot[1202]: time="2024-10-28T14:27:47Z" level=debug msg="resolved context of track" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:27:47 volumio go-librespot[1202]: time="2024-10-28T14:27:47Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:27:47 volumio go-librespot[1202]: time="2024-10-28T14:27:47Z" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:27:47 volumio volumio[958]: info: CoreCommandRouter::volumioPrevious Oct 28 14:27:47 volumio volumio[958]: info: CoreStateMachine::previous Oct 28 14:27:47 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Oct 28 14:27:47 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Oct 28 14:27:47 volumio volumio[958]: info: CoreStateMachine::serviceClearAddPlay Oct 28 14:27:47 volumio volumio[958]: info: CoreCommandRouter::serviceClearAddPlayTracks Oct 28 14:27:47 volumio volumio[958]: error: WARNING: No clearAddPlayTracks method for service spop Oct 28 14:27:47 volumio go-librespot[1202]: time="2024-10-28T14:27:47Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:47 volumio go-librespot[1202]: time="2024-10-28T14:27:47Z" level=trace msg="emitting websocket event: will_play" Oct 28 14:27:47 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5Ck2bAipFCqcmGc24dlHu7","play_origin":"go-librespot"}} Oct 28 14:27:47 volumio go-librespot[1202]: time="2024-10-28T14:27:47Z" level=debug msg="selected format OGG_VORBIS_320 (1e852dd0273759e08380192e844624d792e8b9e2)" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:27:47 volumio go-librespot[1202]: time="2024-10-28T14:27:47Z" level=debug msg="requested aes key for file 1e852dd0273759e08380192e844624d792e8b9e2, gid: 5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:27:47 volumio go-librespot[1202]: time="2024-10-28T14:27:47Z" level=debug msg="fetched first chunk of 14, total size is 7334044 bytes" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:27:47 volumio go-librespot[1202]: time="2024-10-28T14:27:47Z" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:27:48 volumio go-librespot[1202]: time="2024-10-28T14:27:48Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Oct 28 14:27:48 volumio go-librespot[1202]: time="2024-10-28T14:27:48Z" level=info msg="loaded track \"Feuer, Feuer! (feat. Lina Larissa Strahl)\" (paused: false, position: 0ms, duration: 171978ms, prefetched: false)" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:27:48 volumio volumio[958]: info: CoreCommandRouter::volumioPrevious Oct 28 14:27:48 volumio volumio[958]: info: CoreStateMachine::previous Oct 28 14:27:48 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Oct 28 14:27:48 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Oct 28 14:27:48 volumio volumio[958]: info: CoreStateMachine::serviceClearAddPlay Oct 28 14:27:48 volumio volumio[958]: info: CoreCommandRouter::serviceClearAddPlayTracks Oct 28 14:27:48 volumio volumio[958]: error: WARNING: No clearAddPlayTracks method for service spop Oct 28 14:27:48 volumio go-librespot[1202]: time="2024-10-28T14:27:48Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:48 volumio go-librespot[1202]: time="2024-10-28T14:27:48Z" level=trace msg="scheduling prefetch in 142s" Oct 28 14:27:48 volumio go-librespot[1202]: time="2024-10-28T14:27:48Z" level=trace msg="emitting websocket event: metadata" Oct 28 14:27:48 volumio volumio[958]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5Ck2bAipFCqcmGc24dlHu7","name":"Feuer, Feuer! (feat. Lina Larissa Strahl)","artist_names":["Bibi und Tina","Peter Plate","Ulf Leo Sommer","Lina Larissa Strahl"],"album_name":"Bibi und Tina: Mädchen gegen Jungs (Der Original-Soundtrack zum Kinofilm)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02ef840303da8adc7be282090e","position":0,"duration":171978,"release_date":"year:2016 month:1 day:15","track_number":3,"disc_number":1}} Oct 28 14:27:48 volumio volumio[958]: info: CoreCommandRouter::volumioPrevious Oct 28 14:27:48 volumio volumio[958]: info: CoreStateMachine::previous Oct 28 14:27:48 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Oct 28 14:27:48 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Oct 28 14:27:48 volumio volumio[958]: info: CoreStateMachine::serviceClearAddPlay Oct 28 14:27:48 volumio volumio[958]: info: CoreCommandRouter::serviceClearAddPlayTracks Oct 28 14:27:48 volumio volumio[958]: error: WARNING: No clearAddPlayTracks method for service spop Oct 28 14:27:48 volumio go-librespot[1202]: time="2024-10-28T14:27:48Z" level=debug msg="fetched chunk 1/13, size: 524288" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:27:48 volumio go-librespot[1202]: time="2024-10-28T14:27:48Z" level=debug msg="fetched chunk 3/13, size: 524288" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:27:48 volumio go-librespot[1202]: time="2024-10-28T14:27:48Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 28 14:27:48 volumio go-librespot[1202]: time="2024-10-28T14:27:48Z" level=trace msg="emitting websocket event: playing" Oct 28 14:27:48 volumio volumio[958]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5Ck2bAipFCqcmGc24dlHu7","play_origin":"go-librespot"}} Oct 28 14:27:48 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:27:48 volumio volumio[958]: SPOTIFY: {"status":"play","service":"spop","title":"Feuer, Feuer! (feat. Lina Larissa Strahl)","artist":"Bibi und Tina, Peter Plate, Ulf Leo Sommer, Lina Larissa Strahl","album":"Bibi und Tina: Mädchen gegen Jungs (Der Original-Soundtrack zum Kinofilm)","albumart":"https://i.scdn.co/image/ab67616d00001e02ef840303da8adc7be282090e","uri":"spotify:track:5Ck2bAipFCqcmGc24dlHu7","trackType":"spotify","seek":0,"duration":171,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:48 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:27:48 volumio volumio[958]: info: CorePlayQueue::getTrack 10 Oct 28 14:27:48 volumio volumio[958]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Feuer, Feuer! (feat. Lina Larissa Strahl)","artist":"Bibi und Tina, Peter Plate, Ulf Leo Sommer, Lina Larissa Strahl","album":"Bibi und Tina: Mädchen gegen Jungs (Der Original-Soundtrack zum Kinofilm)","albumart":"https://i.scdn.co/image/ab67616d00001e02ef840303da8adc7be282090e","uri":"spotify:track:5Ck2bAipFCqcmGc24dlHu7","trackType":"spotify","seek":0,"duration":171,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:48 volumio volumio[958]: verbose: CURRENT POSITION 10 Oct 28 14:27:48 volumio volumio[958]: info: CoreStateMachine::syncState stateService play Oct 28 14:27:48 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus stop Oct 28 14:27:48 volumio volumio[958]: SPOTIFY: PUSH STATE SPOTIFY Oct 28 14:27:48 volumio volumio[958]: SPOTIFY: {"status":"play","service":"spop","title":"Feuer, Feuer! (feat. Lina Larissa Strahl)","artist":"Bibi und Tina, Peter Plate, Ulf Leo Sommer, Lina Larissa Strahl","album":"Bibi und Tina: Mädchen gegen Jungs (Der Original-Soundtrack zum Kinofilm)","albumart":"https://i.scdn.co/image/ab67616d00001e02ef840303da8adc7be282090e","uri":"spotify:track:5Ck2bAipFCqcmGc24dlHu7","trackType":"spotify","seek":0,"duration":171,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:48 volumio volumio[958]: info: CoreCommandRouter::servicePushState Oct 28 14:27:48 volumio volumio[958]: info: CorePlayQueue::getTrack 10 Oct 28 14:27:48 volumio volumio[958]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Feuer, Feuer! (feat. Lina Larissa Strahl)","artist":"Bibi und Tina, Peter Plate, Ulf Leo Sommer, Lina Larissa Strahl","album":"Bibi und Tina: Mädchen gegen Jungs (Der Original-Soundtrack zum Kinofilm)","albumart":"https://i.scdn.co/image/ab67616d00001e02ef840303da8adc7be282090e","uri":"spotify:track:5Ck2bAipFCqcmGc24dlHu7","trackType":"spotify","seek":0,"duration":171,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 28 14:27:48 volumio volumio[958]: verbose: CURRENT POSITION 10 Oct 28 14:27:49 volumio volumio[958]: info: CoreStateMachine::syncState stateService play Oct 28 14:27:49 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus play Oct 28 14:27:49 volumio volumio[958]: info: Received an update from plugin. extracting info from payload Oct 28 14:27:49 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:49 volumio volumio[958]: info: CorePlayQueue::getTrack 10 Oct 28 14:27:49 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 14:27:49 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:49 volumio volumio[958]: info: CoreStateMachine::pushState Oct 28 14:27:49 volumio volumio[958]: info: CorePlayQueue::getTrack 10 Oct 28 14:27:49 volumio volumio[958]: info: CoreCommandRouter::volumioPushState Oct 28 14:27:49 volumio volumio[958]: info: CoreCommandRouter::volumioPrevious Oct 28 14:27:49 volumio volumio[958]: info: CoreStateMachine::previous Oct 28 14:27:49 volumio volumio[958]: info: CorePlayQueue::getTrack 10 Oct 28 14:27:49 volumio go-librespot[1202]: time="2024-10-28T14:27:49Z" level=debug msg="fetched chunk 2/13, size: 524288" uri="spotify:track:5Ck2bAipFCqcmGc24dlHu7" Oct 28 14:27:49 volumio volumio[958]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 28 14:27:49 volumio volumio[958]: TypeError: Cannot read property 'service' of undefined Oct 28 14:27:49 volumio volumio[958]: at CoreStateMachine.previous (/volumio/app/statemachine.js:1325:97) Oct 28 14:27:49 volumio volumio[958]: at CoreCommandRouter.volumioPrevious (/volumio/app/index.js:95:28) Oct 28 14:27:49 volumio volumio[958]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:270:33) Oct 28 14:27:49 volumio volumio[958]: at Socket.emit (events.js:315:20) Oct 28 14:27:49 volumio volumio[958]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Oct 28 14:27:49 volumio volumio[958]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Oct 28 14:27:49 volumio volumio[958]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 28 14:27:50 volumio kernel: hwmon hwmon1: Undervoltage detected! Oct 28 14:27:52 volumio sudo[2060]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-28 14:26 Oct 28 14:27:52 volumio sudo[2060]: 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="8b17c2f054b42f7617d19172c51eb8801fef450d" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="5ed89c6e5067f886280d87d6c1a3f9930df14028" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 16 Oct 2024 03:57:06 PM CEST" VOLUMIO_VERSION="3.765" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="0d32cf437531a99146c655ee44a741a6"