-- Logs begin at Thu 2019-02-14 11:12:00 CET, end at Sun 2024-10-13 12:52:17 CEST. -- Oct 13 12:51:01 volumio go-librespot[1221]: time="2024-10-13T12:51:01+02:00" level=debug msg="fetched chunk 11/21, size: 524288" uri="spotify:track:5FVd6KXrgO9B3JPmC8OPst" Oct 13 12:51:04 volumio kernel: hwmon hwmon1: Voltage normalised Oct 13 12:51:10 volumio volumio[894]: info: CorePlayQueue::getTrack 6 Oct 13 12:51:10 volumio volumio[894]: info: CoreCommandRouter::executeOnPlugin: spop , goto Oct 13 12:51:11 volumio volumio[894]: info: No valid Plugin REST Endpoint Oct 13 12:51:11 volumio volumio[894]: info: No valid Plugin REST Endpoint Oct 13 12:51:11 volumio volumio[894]: info: No valid Plugin REST Endpoint Oct 13 12:51:15 volumio go-librespot[1221]: time="2024-10-13T12:51:15+02:00" level=debug msg="fetched chunk 12/21, size: 524288" uri="spotify:track:5FVd6KXrgO9B3JPmC8OPst" Oct 13 12:51:26 volumio volumio[894]: info: Preload queue cleared Oct 13 12:51:26 volumio volumio[894]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 13 12:51:26 volumio volumio[894]: info: CoreStateMachine::ClearQueue Oct 13 12:51:26 volumio volumio[894]: info: CoreStateMachine::stop Oct 13 12:51:26 volumio volumio[894]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 12:51:26 volumio volumio[894]: info: CoreStateMachine::stPlaybackTimer Oct 13 12:51:26 volumio volumio[894]: info: CoreStateMachine::updateTrackBlock Oct 13 12:51:26 volumio volumio[894]: info: CorePlayQueue::getTrackBlock Oct 13 12:51:26 volumio volumio[894]: info: CoreStateMachine::pushState Oct 13 12:51:26 volumio volumio[894]: info: CorePlayQueue::getTrack 6 Oct 13 12:51:26 volumio volumio[894]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 12:51:26 volumio volumio[894]: info: CoreCommandRouter::volumioPushState Oct 13 12:51:26 volumio volumio[894]: info: CoreStateMachine::serviceStop Oct 13 12:51:26 volumio volumio[894]: info: CorePlayQueue::getTrack 6 Oct 13 12:51:26 volumio volumio[894]: info: CoreCommandRouter::serviceStop Oct 13 12:51:26 volumio volumio[894]: info: Spotify Stop Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: SPOTIFY STOP Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: {"status":"play","position":6,"title":"Do I Wanna Know?","artist":"Arctic Monkeys","album":"AM","albumart":"https://i.scdn.co/image/ab67616d0000b2734ae1c4c5c45aabe565499163","uri":"spotify:track:5FVd6KXrgO9B3JPmC8OPst","trackType":"spotify","codec":"ogg","seek":74055,"duration":272,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Oct 13 12:51:26 volumio volumio[894]: info: Sending Spotify command to local API: /player/pause Oct 13 12:51:26 volumio volumio[894]: info: CorePlayQueue::clearPlayQueue Oct 13 12:51:26 volumio volumio[894]: info: CorePlayQueue::saveQueue Oct 13 12:51:26 volumio volumio[894]: info: CoreCommandRouter::volumioPushQueue Oct 13 12:51:26 volumio volumio[894]: info: CoreStateMachine::addQueueItems Oct 13 12:51:26 volumio volumio[894]: info: CorePlayQueue::addQueueItems Oct 13 12:51:26 volumio volumio[894]: info: Preload queue cleared Oct 13 12:51:26 volumio volumio[894]: info: Adding Item to queue: spotify:track:5XeFesFbtLpXzIVDNQP22n Oct 13 12:51:26 volumio volumio[894]: info: Exploding uri spotify:track:5XeFesFbtLpXzIVDNQP22n in service spop Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: EXPLODING URI:spotify:track:5XeFesFbtLpXzIVDNQP22n Oct 13 12:51:26 volumio volumio[894]: info: Adding Item to queue: spotify:track:0BxE4FqsDD1Ot4YuBXwAPp Oct 13 12:51:26 volumio volumio[894]: info: Exploding uri spotify:track:0BxE4FqsDD1Ot4YuBXwAPp in service spop Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: EXPLODING URI:spotify:track:0BxE4FqsDD1Ot4YuBXwAPp Oct 13 12:51:26 volumio volumio[894]: info: Adding Item to queue: spotify:track:086myS9r57YsLbJpU0TgK9 Oct 13 12:51:26 volumio volumio[894]: info: Exploding uri spotify:track:086myS9r57YsLbJpU0TgK9 in service spop Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: EXPLODING URI:spotify:track:086myS9r57YsLbJpU0TgK9 Oct 13 12:51:26 volumio volumio[894]: info: Adding Item to queue: spotify:track:5FVd6KXrgO9B3JPmC8OPst Oct 13 12:51:26 volumio volumio[894]: info: Using cached record of: spotify:track:5FVd6KXrgO9B3JPmC8OPst Oct 13 12:51:26 volumio volumio[894]: info: Adding Item to queue: spotify:track:2AT8iROs4FQueDv2c8q2KE Oct 13 12:51:26 volumio volumio[894]: info: Exploding uri spotify:track:2AT8iROs4FQueDv2c8q2KE in service spop Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: EXPLODING URI:spotify:track:2AT8iROs4FQueDv2c8q2KE Oct 13 12:51:26 volumio volumio[894]: info: Adding Item to queue: spotify:track:2x8evxqUlF0eRabbW2JBJd Oct 13 12:51:26 volumio volumio[894]: info: Exploding uri spotify:track:2x8evxqUlF0eRabbW2JBJd in service spop Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: EXPLODING URI:spotify:track:2x8evxqUlF0eRabbW2JBJd Oct 13 12:51:26 volumio volumio[894]: info: Adding Item to queue: spotify:track:0NdTUS4UiNYCNn5FgVqKQY Oct 13 12:51:26 volumio volumio[894]: info: Exploding uri spotify:track:0NdTUS4UiNYCNn5FgVqKQY in service spop Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: EXPLODING URI:spotify:track:0NdTUS4UiNYCNn5FgVqKQY Oct 13 12:51:26 volumio volumio[894]: info: Adding Item to queue: spotify:track:5TTGoX70AFrTvuEtqHK37S Oct 13 12:51:26 volumio volumio[894]: info: Exploding uri spotify:track:5TTGoX70AFrTvuEtqHK37S in service spop Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: EXPLODING URI:spotify:track:5TTGoX70AFrTvuEtqHK37S Oct 13 12:51:26 volumio volumio[894]: info: Adding Item to queue: spotify:track:7nzsY8vlnKdvGOEE0rjAXZ Oct 13 12:51:26 volumio volumio[894]: info: Exploding uri spotify:track:7nzsY8vlnKdvGOEE0rjAXZ in service spop Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: EXPLODING URI:spotify:track:7nzsY8vlnKdvGOEE0rjAXZ Oct 13 12:51:26 volumio volumio[894]: info: Adding Item to queue: spotify:track:2LGdO5MtFdyphi2EihANZG Oct 13 12:51:26 volumio volumio[894]: info: Exploding uri spotify:track:2LGdO5MtFdyphi2EihANZG in service spop Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: EXPLODING URI:spotify:track:2LGdO5MtFdyphi2EihANZG Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 12:51:26 volumio go-librespot[1221]: time="2024-10-13T12:51:26+02:00" level=debug msg="pause track at 121520ms" Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2AT8iROs4FQueDv2c8q2KE","service":"spop","name":"R U Mine?","artist":"Arctic Monkeys","album":"AM","type":"song","duration":201,"albumart":"https://i.scdn.co/image/ab67616d0000b2734ae1c4c5c45aabe565499163","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0BxE4FqsDD1Ot4YuBXwAPp","service":"spop","name":"505","artist":"Arctic Monkeys","album":"Favourite Worst Nightmare","type":"song","duration":253,"albumart":"https://i.scdn.co/image/ab67616d0000b273b1f8da74f225fa1225cdface","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5XeFesFbtLpXzIVDNQP22n","service":"spop","name":"I Wanna Be Yours","artist":"Arctic Monkeys","album":"AM","type":"song","duration":183,"albumart":"https://i.scdn.co/image/ab67616d0000b2734ae1c4c5c45aabe565499163","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:086myS9r57YsLbJpU0TgK9","service":"spop","name":"Why'd You Only Call Me When You're High?","artist":"Arctic Monkeys","album":"AM","type":"song","duration":161,"albumart":"https://i.scdn.co/image/ab67616d0000b2734ae1c4c5c45aabe565499163","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2x8evxqUlF0eRabbW2JBJd","service":"spop","name":"Fluorescent Adolescent","artist":"Arctic Monkeys","album":"Favourite Worst Nightmare","type":"song","duration":183,"albumart":"https://i.scdn.co/image/ab67616d0000b273b1f8da74f225fa1225cdface","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7nzsY8vlnKdvGOEE0rjAXZ","service":"spop","name":"Arabella","artist":"Arctic Monkeys","album":"AM","type":"song","duration":207,"albumart":"https://i.scdn.co/image/ab67616d0000b2734ae1c4c5c45aabe565499163","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0NdTUS4UiNYCNn5FgVqKQY","service":"spop","name":"Snap Out Of It","artist":"Arctic Monkeys","album":"AM","type":"song","duration":193,"albumart":"https://i.scdn.co/image/ab67616d0000b2734ae1c4c5c45aabe565499163","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5TTGoX70AFrTvuEtqHK37S","service":"spop","name":"No. 1 Party Anthem","artist":"Arctic Monkeys","album":"AM","type":"song","duration":243,"albumart":"https://i.scdn.co/image/ab67616d0000b2734ae1c4c5c45aabe565499163","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2LGdO5MtFdyphi2EihANZG","service":"spop","name":"Knee Socks","artist":"Arctic Monkeys","album":"AM","type":"song","duration":257,"albumart":"https://i.scdn.co/image/ab67616d0000b2734ae1c4c5c45aabe565499163","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 13 12:51:26 volumio volumio[894]: info: CoreCommandRouter::volumioPushQueue Oct 13 12:51:26 volumio volumio[894]: info: CorePlayQueue::saveQueue Oct 13 12:51:26 volumio volumio[894]: info: CoreStateMachine::updateTrackBlock Oct 13 12:51:26 volumio volumio[894]: info: CorePlayQueue::getTrackBlock Oct 13 12:51:26 volumio volumio[894]: info: CoreCommandRouter::volumioPlay Oct 13 12:51:26 volumio volumio[894]: info: CoreStateMachine::play index 8 Oct 13 12:51:26 volumio volumio[894]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 12:51:26 volumio volumio[894]: info: CoreStateMachine::stop Oct 13 12:51:26 volumio volumio[894]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 12:51:26 volumio volumio[894]: info: CoreStateMachine::play index undefined Oct 13 12:51:26 volumio volumio[894]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 12:51:26 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:51:26 volumio volumio[894]: info: CoreStateMachine::startPlaybackTimer Oct 13 12:51:26 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:51:26 volumio volumio[894]: info: [1728816686700] ControllerSpotify::clearAddPlayTrack Oct 13 12:51:26 volumio volumio[894]: info: Sending Spotify command with payload to local API: /player/play Oct 13 12:51:26 volumio go-librespot[1221]: time="2024-10-13T12:51:26+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 12:51:26 volumio go-librespot[1221]: time="2024-10-13T12:51:26+02:00" level=debug msg="resolved context of track" uri="spotify:track:7nzsY8vlnKdvGOEE0rjAXZ" Oct 13 12:51:26 volumio go-librespot[1221]: time="2024-10-13T12:51:26+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:7nzsY8vlnKdvGOEE0rjAXZ" Oct 13 12:51:26 volumio go-librespot[1221]: time="2024-10-13T12:51:26+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:7nzsY8vlnKdvGOEE0rjAXZ" Oct 13 12:51:26 volumio go-librespot[1221]: time="2024-10-13T12:51:26+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 12:51:26 volumio go-librespot[1221]: time="2024-10-13T12:51:26+02:00" level=trace msg="emitting websocket event: will_play" Oct 13 12:51:26 volumio volumio[894]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7nzsY8vlnKdvGOEE0rjAXZ","play_origin":"go-librespot"}} Oct 13 12:51:27 volumio go-librespot[1221]: time="2024-10-13T12:51:27+02:00" level=debug msg="selected format OGG_VORBIS_320 (af2e730bf4edad47fe70edd7fa63e17265d1f6b4)" uri="spotify:track:7nzsY8vlnKdvGOEE0rjAXZ" Oct 13 12:51:27 volumio go-librespot[1221]: time="2024-10-13T12:51:27+02:00" level=debug msg="requested aes key for file af2e730bf4edad47fe70edd7fa63e17265d1f6b4, gid: 7nzsY8vlnKdvGOEE0rjAXZ" Oct 13 12:51:27 volumio go-librespot[1221]: time="2024-10-13T12:51:27+02:00" level=debug msg="fetched first chunk of 16, total size is 7865248 bytes" uri="spotify:track:7nzsY8vlnKdvGOEE0rjAXZ" Oct 13 12:51:27 volumio go-librespot[1221]: time="2024-10-13T12:51:27+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:7nzsY8vlnKdvGOEE0rjAXZ" Oct 13 12:51:27 volumio go-librespot[1221]: time="2024-10-13T12:51:27+02:00" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:7nzsY8vlnKdvGOEE0rjAXZ" Oct 13 12:51:27 volumio go-librespot[1221]: time="2024-10-13T12:51:27+02:00" 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 13 12:51:27 volumio go-librespot[1221]: time="2024-10-13T12:51:27+02:00" level=info msg="loaded track \"Arabella\" (paused: false, position: 0ms, duration: 207356ms, prefetched: false)" uri="spotify:track:7nzsY8vlnKdvGOEE0rjAXZ" Oct 13 12:51:27 volumio go-librespot[1221]: time="2024-10-13T12:51:27+02:00" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:7nzsY8vlnKdvGOEE0rjAXZ" Oct 13 12:51:27 volumio go-librespot[1221]: time="2024-10-13T12:51:27+02:00" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:7nzsY8vlnKdvGOEE0rjAXZ" Oct 13 12:51:27 volumio go-librespot[1221]: time="2024-10-13T12:51:27+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 12:51:27 volumio go-librespot[1221]: time="2024-10-13T12:51:27+02:00" level=trace msg="scheduling prefetch in 177s" Oct 13 12:51:27 volumio go-librespot[1221]: time="2024-10-13T12:51:27+02:00" level=trace msg="emitting websocket event: metadata" Oct 13 12:51:27 volumio volumio[894]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7nzsY8vlnKdvGOEE0rjAXZ","name":"Arabella","artist_names":["Arctic Monkeys"],"album_name":"AM","album_cover_url":"https://i.scdn.co/image/ab67616d00001e024ae1c4c5c45aabe565499163","position":0,"duration":207356,"release_date":"year:2013 month:9 day:9","track_number":4,"disc_number":1}} Oct 13 12:51:27 volumio go-librespot[1221]: time="2024-10-13T12:51:27+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 12:51:27 volumio go-librespot[1221]: time="2024-10-13T12:51:27+02:00" level=trace msg="emitting websocket event: paused" Oct 13 12:51:27 volumio volumio[894]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:7nzsY8vlnKdvGOEE0rjAXZ","play_origin":"go-librespot"}} Oct 13 12:51:27 volumio volumio[894]: SPOTIFY: PUSH STATE SPOTIFY Oct 13 12:51:27 volumio volumio[894]: SPOTIFY: {"status":"pause","service":"spop","title":"Arabella","artist":"Arctic Monkeys","album":"AM","albumart":"https://i.scdn.co/image/ab67616d00001e024ae1c4c5c45aabe565499163","uri":"spotify:track:7nzsY8vlnKdvGOEE0rjAXZ","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 13 12:51:27 volumio volumio[894]: info: CoreCommandRouter::servicePushState Oct 13 12:51:27 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:51:27 volumio volumio[894]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Arabella","artist":"Arctic Monkeys","album":"AM","albumart":"https://i.scdn.co/image/ab67616d00001e024ae1c4c5c45aabe565499163","uri":"spotify:track:7nzsY8vlnKdvGOEE0rjAXZ","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 13 12:51:27 volumio volumio[894]: verbose: CURRENT POSITION 8 Oct 13 12:51:27 volumio volumio[894]: info: CoreStateMachine::syncState stateService pause Oct 13 12:51:27 volumio volumio[894]: info: CoreStateMachine::syncState currentStatus stop Oct 13 12:51:27 volumio volumio[894]: info: CoreStateMachine::pushState Oct 13 12:51:27 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:51:27 volumio volumio[894]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 12:51:27 volumio volumio[894]: info: CoreCommandRouter::volumioPushState Oct 13 12:51:27 volumio volumio[894]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 12:51:27 volumio go-librespot[1221]: time="2024-10-13T12:51:27+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 12:51:27 volumio go-librespot[1221]: time="2024-10-13T12:51:27+02:00" level=trace msg="emitting websocket event: playing" Oct 13 12:51:27 volumio volumio[894]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7nzsY8vlnKdvGOEE0rjAXZ","play_origin":"go-librespot"}} Oct 13 12:51:27 volumio volumio[894]: SPOTIFY: PUSH STATE SPOTIFY Oct 13 12:51:27 volumio volumio[894]: SPOTIFY: {"status":"play","service":"spop","title":"Arabella","artist":"Arctic Monkeys","album":"AM","albumart":"https://i.scdn.co/image/ab67616d00001e024ae1c4c5c45aabe565499163","uri":"spotify:track:7nzsY8vlnKdvGOEE0rjAXZ","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 13 12:51:27 volumio volumio[894]: info: CoreCommandRouter::servicePushState Oct 13 12:51:27 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:51:27 volumio volumio[894]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Arabella","artist":"Arctic Monkeys","album":"AM","albumart":"https://i.scdn.co/image/ab67616d00001e024ae1c4c5c45aabe565499163","uri":"spotify:track:7nzsY8vlnKdvGOEE0rjAXZ","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 13 12:51:27 volumio volumio[894]: verbose: CURRENT POSITION 8 Oct 13 12:51:27 volumio volumio[894]: info: CoreStateMachine::syncState stateService play Oct 13 12:51:27 volumio volumio[894]: info: CoreStateMachine::syncState currentStatus stop Oct 13 12:51:27 volumio volumio[894]: SPOTIFY: PUSH STATE SPOTIFY Oct 13 12:51:27 volumio volumio[894]: SPOTIFY: {"status":"play","service":"spop","title":"Arabella","artist":"Arctic Monkeys","album":"AM","albumart":"https://i.scdn.co/image/ab67616d00001e024ae1c4c5c45aabe565499163","uri":"spotify:track:7nzsY8vlnKdvGOEE0rjAXZ","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 13 12:51:27 volumio volumio[894]: info: CoreCommandRouter::servicePushState Oct 13 12:51:27 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:51:27 volumio volumio[894]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Arabella","artist":"Arctic Monkeys","album":"AM","albumart":"https://i.scdn.co/image/ab67616d00001e024ae1c4c5c45aabe565499163","uri":"spotify:track:7nzsY8vlnKdvGOEE0rjAXZ","trackType":"spotify","seek":0,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 13 12:51:27 volumio volumio[894]: verbose: CURRENT POSITION 8 Oct 13 12:51:27 volumio volumio[894]: info: CoreStateMachine::syncState stateService play Oct 13 12:51:27 volumio volumio[894]: info: CoreStateMachine::syncState currentStatus play Oct 13 12:51:27 volumio volumio[894]: info: Received an update from plugin. extracting info from payload Oct 13 12:51:27 volumio volumio[894]: info: CoreStateMachine::pushState Oct 13 12:51:27 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:51:27 volumio volumio[894]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 12:51:27 volumio volumio[894]: info: CoreCommandRouter::volumioPushState Oct 13 12:51:28 volumio volumio[894]: info: CoreStateMachine::pushState Oct 13 12:51:28 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:51:28 volumio volumio[894]: info: CoreCommandRouter::volumioPushState Oct 13 12:51:28 volumio volumio[894]: info: [LastFM] Current track has sufficient metadata: title (Arabella) and artist (Arctic Monkeys) passed on explicitly Oct 13 12:51:28 volumio volumio[894]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 12:51:28 volumio volumio[894]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 12:51:28 volumio volumio[894]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Arabella","mbid":"36569a1a-55c5-4bc4-ae12-46e49df94921","url":"https://www.last.fm/music/Arctic+Monkeys/_/Arabella","duration":"207000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"1237932","playcount":"13859207","artist":{"name":"Arctic Monkeys","mbid":"ada7a83c-e3e1-40f1-93f9-3e73dbc9298a","url":"https://www.last.fm/music/Arctic+Monkeys"},"album":{"@":{"position":"4"},"artist":"Arctic Monkeys","title":"AM","mbid":"bf584cf2-dc33-433e-b8b2-b85578822726","url":"https://www.last.fm/music/Arctic+Monkeys/AM","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/f579e414e20f40969185e41182d72472.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/f579e414e20f40969185e41182d72472.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/f579e414e20f40969185e41182d72472.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/f579e414e20f40969185e41182d72472.png","@":{"size":"extralarge"}}]},"userplaycount":"0","userloved":"0","toptags":{"tag":[{"name":"indie rock","url":"https://www.last.fm/tag/indie+rock"},{"name":"rock","url":"https://www.last.fm/tag/rock"},{"name":"alternative","url":"https://www.last.fm/tag/alternative"},{"name":"arctic monkeys","url":"https://www.last.fm/tag/arctic+monkeys"},{"name":"Post-punk revival","url":"https://www.last.fm/tag/Post-punk+revival"}]},"wiki":{"published":"27 May 2016, 18:51","summary":"A song about a space-aged lover named Arabella serves as track four on the Arctic Monkeys' fifth album \"AM\". It furthers the album’s motif of passion’s incessant pull, both for better and worse, with the titular woman’s unavoidable appeal. The song was confirmed as the album's fifth single by the band and their label Domino and impacted radio in Italy on 28 January 2014 and the United Kingdom on 10 March 2014. A physical 7\" vinyl single was also planned for release on 28 March 2014 but was ultimately canceled Read more on Last.fm.","content":"A song about a space-aged lover named Arabella serves as track four on the Arctic Monkeys' fifth album \"AM\". It furthers the album’s motif of passion’s incessant pull, both for better and worse, with the titular woman’s unavoidable appeal. The song was confirmed as the album's fifth single by the band and their label Domino and impacted radio in Italy on 28 January 2014 and the United Kingdom on 10 March 2014. A physical 7\" vinyl single was also planned for release on 28 March 2014 but was ultimately canceled The song is described by Far Out magazine as a \"fusing of late ‘90s hip-hop and R&B with ‘70s hard rock,\" they also noted musical references \"to the likes of Sabbath or Zeppelin and the futurism of Dr. Dre, combined with lyrical extracts like “Arabella’s got a ‘70s head, but she’s a modern lover…she’s made of outer space”\". \"Arabella\" was played live for the first time on 30 August 2013, during Zurich Openair festival performance, which was a part of the AM Tour. The band often plays part of Black Sabbath's \"War Pigs\" during live performances of the song, done to give Alex Turner time to equip a guitar for the solo. The part \"War Pigs\" is played due to the similarities between the riffs of the two songs. An official music video for the song, directed by English director Jake Nava, premiered on 2 March 2014. In September 2013, following the release of AM, \"Arabella\" charted at number 155 on the UK Singles Chart, number 26 on the UK Indie Chart, and number 7 on the Ultratip chart of Belgium's Flanders region. Following the announcement of its single release in March 2014, the single re-entered the UK Singles and Indie charts, peaking at numbers 70 and 9 respectively. \"Arabella\" was added to the BBC Radio 1 playlist on the B-list on 10 February 2014. Read more on Last.fm. User-contributed text is available under the Creative Commons By-SA License; additional terms may apply."}}} Oct 13 12:51:32 volumio volumio[894]: info: CoreCommandRouter::volumioGetState Oct 13 12:51:32 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:51:39 volumio volumio[894]: info: CoreCommandRouter::volumioGetState Oct 13 12:51:39 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:51:40 volumio volumio[894]: info: CoreCommandRouter::volumioSeek Oct 13 12:51:40 volumio volumio[894]: info: CoreStateMachine::seek Oct 13 12:51:40 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:51:40 volumio volumio[894]: info: TRACKBLOCK {"uri":"spotify:track:7nzsY8vlnKdvGOEE0rjAXZ","service":"spop","name":"Arabella","artist":"Arctic Monkeys","album":"AM","type":"song","duration":207,"albumart":"https://i.scdn.co/image/ab67616d0000b2734ae1c4c5c45aabe565499163","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify","channels":2} Oct 13 12:51:40 volumio volumio[894]: info: CoreStateMachine::startPlaybackTimer Oct 13 12:51:40 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:51:40 volumio volumio[894]: info: Spotify seek to: 68000 Oct 13 12:51:40 volumio volumio[894]: info: Sending Spotify command with payload to local API: /player/seek Oct 13 12:51:40 volumio volumio[894]: info: CoreStateMachine::pushState Oct 13 12:51:40 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:51:40 volumio volumio[894]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 12:51:40 volumio volumio[894]: info: CoreCommandRouter::volumioPushState Oct 13 12:51:40 volumio volumio[894]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 12:51:40 volumio go-librespot[1221]: time="2024-10-13T12:51:40+02:00" level=debug msg="seek track to 68000ms" Oct 13 12:51:40 volumio go-librespot[1221]: time="2024-10-13T12:51:40+02:00" level=debug msg="fetched chunk 4/15, size: 524288" uri="spotify:track:7nzsY8vlnKdvGOEE0rjAXZ" Oct 13 12:51:40 volumio go-librespot[1221]: time="2024-10-13T12:51:40+02:00" level=trace msg="seek to 68000ms (diff: 121ms, samples: 2998800, bytes: 2485165)" uri="spotify:track:7nzsY8vlnKdvGOEE0rjAXZ" Oct 13 12:51:40 volumio go-librespot[1221]: time="2024-10-13T12:51:40+02:00" level=debug msg="fetched chunk 7/15, size: 524288" uri="spotify:track:7nzsY8vlnKdvGOEE0rjAXZ" Oct 13 12:51:40 volumio go-librespot[1221]: time="2024-10-13T12:51:40+02:00" level=debug msg="fetched chunk 5/15, size: 524288" uri="spotify:track:7nzsY8vlnKdvGOEE0rjAXZ" Oct 13 12:51:40 volumio go-librespot[1221]: time="2024-10-13T12:51:40+02:00" level=debug msg="fetched chunk 6/15, size: 524288" uri="spotify:track:7nzsY8vlnKdvGOEE0rjAXZ" Oct 13 12:51:40 volumio go-librespot[1221]: time="2024-10-13T12:51:40+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 12:51:40 volumio go-librespot[1221]: time="2024-10-13T12:51:40+02:00" level=trace msg="scheduling prefetch in 109s" Oct 13 12:51:40 volumio go-librespot[1221]: time="2024-10-13T12:51:40+02:00" level=trace msg="emitting websocket event: seek" Oct 13 12:51:40 volumio volumio[894]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:7nzsY8vlnKdvGOEE0rjAXZ","position":68000,"duration":207356,"play_origin":"go-librespot"}} Oct 13 12:51:40 volumio volumio[894]: SPOTIFY: PUSH STATE SPOTIFY Oct 13 12:51:40 volumio volumio[894]: SPOTIFY: {"status":"play","service":"spop","title":"Arabella","artist":"Arctic Monkeys","album":"AM","albumart":"https://i.scdn.co/image/ab67616d00001e024ae1c4c5c45aabe565499163","uri":"spotify:track:7nzsY8vlnKdvGOEE0rjAXZ","trackType":"spotify","seek":68000,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 13 12:51:40 volumio volumio[894]: info: CoreCommandRouter::servicePushState Oct 13 12:51:40 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:51:40 volumio volumio[894]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Arabella","artist":"Arctic Monkeys","album":"AM","albumart":"https://i.scdn.co/image/ab67616d00001e024ae1c4c5c45aabe565499163","uri":"spotify:track:7nzsY8vlnKdvGOEE0rjAXZ","trackType":"spotify","seek":68000,"duration":207,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 13 12:51:40 volumio volumio[894]: verbose: CURRENT POSITION 8 Oct 13 12:51:40 volumio volumio[894]: info: CoreStateMachine::syncState stateService play Oct 13 12:51:40 volumio volumio[894]: info: CoreStateMachine::syncState currentStatus play Oct 13 12:51:40 volumio volumio[894]: info: Received an update from plugin. extracting info from payload Oct 13 12:51:40 volumio volumio[894]: info: CoreStateMachine::pushState Oct 13 12:51:40 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:51:40 volumio volumio[894]: info: CoreCommandRouter::volumioPushState Oct 13 12:51:40 volumio volumio[894]: info: CoreStateMachine::pushState Oct 13 12:51:40 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:51:40 volumio volumio[894]: info: CoreCommandRouter::volumioPushState Oct 13 12:51:40 volumio volumio[894]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 12:51:40 volumio volumio[894]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 12:51:41 volumio kernel: hwmon hwmon1: Undervoltage detected! Oct 13 12:51:43 volumio go-librespot[1221]: time="2024-10-13T12:51:43+02:00" level=debug msg="fetched chunk 8/15, size: 524288" uri="spotify:track:7nzsY8vlnKdvGOEE0rjAXZ" Oct 13 12:51:45 volumio kernel: hwmon hwmon1: Voltage normalised Oct 13 12:51:46 volumio volumio[894]: info: CoreCommandRouter::volumioGetState Oct 13 12:51:46 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:51:52 volumio volumio[894]: info: CoreCommandRouter::volumioGetState Oct 13 12:51:52 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:51:56 volumio go-librespot[1221]: time="2024-10-13T12:51:56+02:00" level=debug msg="fetched chunk 9/15, size: 524288" uri="spotify:track:7nzsY8vlnKdvGOEE0rjAXZ" Oct 13 12:51:57 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:51:57 volumio volumio[894]: info: CoreCommandRouter::executeOnPlugin: spop , goto Oct 13 12:51:58 volumio kernel: hwmon hwmon1: Undervoltage detected! Oct 13 12:51:58 volumio volumio[894]: info: No valid Plugin REST Endpoint Oct 13 12:51:58 volumio volumio[894]: info: No valid Plugin REST Endpoint Oct 13 12:51:58 volumio volumio[894]: info: No valid Plugin REST Endpoint Oct 13 12:51:58 volumio volumio[894]: info: No valid Plugin REST Endpoint Oct 13 12:51:58 volumio volumio[894]: info: No valid Plugin REST Endpoint Oct 13 12:51:58 volumio volumio[894]: info: No valid Plugin REST Endpoint Oct 13 12:52:01 volumio volumio[894]: info: Preload queue cleared Oct 13 12:52:01 volumio volumio[894]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 13 12:52:01 volumio volumio[894]: info: CoreStateMachine::ClearQueue Oct 13 12:52:01 volumio volumio[894]: info: CoreStateMachine::stop Oct 13 12:52:01 volumio volumio[894]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 12:52:01 volumio volumio[894]: info: CoreStateMachine::stPlaybackTimer Oct 13 12:52:01 volumio volumio[894]: info: CoreStateMachine::updateTrackBlock Oct 13 12:52:01 volumio volumio[894]: info: CorePlayQueue::getTrackBlock Oct 13 12:52:01 volumio volumio[894]: info: CoreStateMachine::pushState Oct 13 12:52:01 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:52:01 volumio volumio[894]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 12:52:01 volumio volumio[894]: info: CoreCommandRouter::volumioPushState Oct 13 12:52:01 volumio volumio[894]: info: CoreStateMachine::serviceStop Oct 13 12:52:01 volumio volumio[894]: info: CorePlayQueue::getTrack 8 Oct 13 12:52:01 volumio volumio[894]: info: CoreCommandRouter::serviceStop Oct 13 12:52:01 volumio volumio[894]: info: Spotify Stop Oct 13 12:52:01 volumio volumio[894]: SPOTIFY: SPOTIFY STOP Oct 13 12:52:01 volumio volumio[894]: SPOTIFY: {"status":"play","position":8,"title":"Arabella","artist":"Arctic Monkeys","album":"AM","albumart":"https://i.scdn.co/image/ab67616d0000b2734ae1c4c5c45aabe565499163","uri":"spotify:track:7nzsY8vlnKdvGOEE0rjAXZ","trackType":"spotify","codec":"ogg","seek":68000,"duration":207,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Oct 13 12:52:01 volumio volumio[894]: info: Sending Spotify command to local API: /player/pause Oct 13 12:52:01 volumio volumio[894]: info: CorePlayQueue::clearPlayQueue Oct 13 12:52:01 volumio volumio[894]: info: CorePlayQueue::saveQueue Oct 13 12:52:01 volumio volumio[894]: info: CoreCommandRouter::volumioPushQueue Oct 13 12:52:01 volumio volumio[894]: info: CoreStateMachine::addQueueItems Oct 13 12:52:01 volumio volumio[894]: info: CorePlayQueue::addQueueItems Oct 13 12:52:01 volumio volumio[894]: info: Preload queue cleared Oct 13 12:52:01 volumio volumio[894]: info: Adding Item to queue: spotify:track:5XeFesFbtLpXzIVDNQP22n Oct 13 12:52:01 volumio volumio[894]: info: Using cached record of: spotify:track:5XeFesFbtLpXzIVDNQP22n Oct 13 12:52:01 volumio volumio[894]: info: Adding Item to queue: spotify:track:0BxE4FqsDD1Ot4YuBXwAPp Oct 13 12:52:01 volumio volumio[894]: info: Using cached record of: spotify:track:0BxE4FqsDD1Ot4YuBXwAPp Oct 13 12:52:01 volumio volumio[894]: info: Adding Item to queue: spotify:track:086myS9r57YsLbJpU0TgK9 Oct 13 12:52:01 volumio volumio[894]: info: Using cached record of: spotify:track:086myS9r57YsLbJpU0TgK9 Oct 13 12:52:01 volumio volumio[894]: info: Adding Item to queue: spotify:track:5FVd6KXrgO9B3JPmC8OPst Oct 13 12:52:01 volumio volumio[894]: info: Using cached record of: spotify:track:5FVd6KXrgO9B3JPmC8OPst Oct 13 12:52:01 volumio volumio[894]: info: Adding Item to queue: spotify:track:2AT8iROs4FQueDv2c8q2KE Oct 13 12:52:01 volumio volumio[894]: info: Using cached record of: spotify:track:2AT8iROs4FQueDv2c8q2KE Oct 13 12:52:01 volumio volumio[894]: info: Adding Item to queue: spotify:track:2x8evxqUlF0eRabbW2JBJd Oct 13 12:52:01 volumio volumio[894]: info: Using cached record of: spotify:track:2x8evxqUlF0eRabbW2JBJd Oct 13 12:52:01 volumio volumio[894]: info: Adding Item to queue: spotify:track:0NdTUS4UiNYCNn5FgVqKQY Oct 13 12:52:01 volumio volumio[894]: info: Using cached record of: spotify:track:0NdTUS4UiNYCNn5FgVqKQY Oct 13 12:52:01 volumio volumio[894]: info: Adding Item to queue: spotify:track:5TTGoX70AFrTvuEtqHK37S Oct 13 12:52:01 volumio volumio[894]: info: Using cached record of: spotify:track:5TTGoX70AFrTvuEtqHK37S Oct 13 12:52:01 volumio volumio[894]: info: Adding Item to queue: spotify:track:7nzsY8vlnKdvGOEE0rjAXZ Oct 13 12:52:01 volumio volumio[894]: info: Using cached record of: spotify:track:7nzsY8vlnKdvGOEE0rjAXZ Oct 13 12:52:01 volumio volumio[894]: info: Adding Item to queue: spotify:track:2LGdO5MtFdyphi2EihANZG Oct 13 12:52:01 volumio volumio[894]: info: Using cached record of: spotify:track:2LGdO5MtFdyphi2EihANZG Oct 13 12:52:01 volumio volumio[894]: info: CoreCommandRouter::volumioPushQueue Oct 13 12:52:01 volumio volumio[894]: info: CorePlayQueue::saveQueue Oct 13 12:52:01 volumio volumio[894]: info: CoreStateMachine::updateTrackBlock Oct 13 12:52:01 volumio volumio[894]: info: CorePlayQueue::getTrackBlock Oct 13 12:52:01 volumio volumio[894]: info: CoreCommandRouter::volumioPlay Oct 13 12:52:01 volumio volumio[894]: info: CoreStateMachine::play index 0 Oct 13 12:52:01 volumio volumio[894]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 12:52:01 volumio volumio[894]: info: CoreStateMachine::stop Oct 13 12:52:01 volumio volumio[894]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 12:52:01 volumio volumio[894]: info: CoreStateMachine::play index undefined Oct 13 12:52:01 volumio volumio[894]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 12:52:01 volumio volumio[894]: info: CorePlayQueue::getTrack 0 Oct 13 12:52:01 volumio volumio[894]: info: CoreStateMachine::startPlaybackTimer Oct 13 12:52:01 volumio volumio[894]: info: CorePlayQueue::getTrack 0 Oct 13 12:52:01 volumio volumio[894]: info: [1728816721615] ControllerSpotify::clearAddPlayTrack Oct 13 12:52:01 volumio volumio[894]: info: Sending Spotify command with payload to local API: /player/play Oct 13 12:52:01 volumio volumio[894]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 12:52:01 volumio go-librespot[1221]: time="2024-10-13T12:52:01+02:00" level=debug msg="pause track at 89291ms" Oct 13 12:52:01 volumio go-librespot[1221]: time="2024-10-13T12:52:01+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=trace msg="emitting websocket event: paused" Oct 13 12:52:02 volumio volumio[894]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:7nzsY8vlnKdvGOEE0rjAXZ","play_origin":"go-librespot"}} Oct 13 12:52:02 volumio volumio[894]: SPOTIFY: PUSH STATE SPOTIFY Oct 13 12:52:02 volumio volumio[894]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":1000,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 13 12:52:02 volumio volumio[894]: info: CoreCommandRouter::servicePushState Oct 13 12:52:02 volumio volumio[894]: info: CorePlayQueue::getTrack 0 Oct 13 12:52:02 volumio volumio[894]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":1000,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 13 12:52:02 volumio volumio[894]: verbose: CURRENT POSITION 0 Oct 13 12:52:02 volumio volumio[894]: info: CoreStateMachine::syncState stateService pause Oct 13 12:52:02 volumio volumio[894]: info: CoreStateMachine::syncState currentStatus stop Oct 13 12:52:02 volumio volumio[894]: info: CoreStateMachine::pushState Oct 13 12:52:02 volumio volumio[894]: info: CorePlayQueue::getTrack 0 Oct 13 12:52:02 volumio volumio[894]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 12:52:02 volumio volumio[894]: info: CoreCommandRouter::volumioPushState Oct 13 12:52:02 volumio volumio[894]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=debug msg="resolved context of track" uri="spotify:track:5XeFesFbtLpXzIVDNQP22n" Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:5XeFesFbtLpXzIVDNQP22n" Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:5XeFesFbtLpXzIVDNQP22n" Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=trace msg="emitting websocket event: will_play" Oct 13 12:52:02 volumio volumio[894]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5XeFesFbtLpXzIVDNQP22n","play_origin":"go-librespot"}} Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=debug msg="selected format OGG_VORBIS_320 (65e016df53012c00d63f36e72741de66e4cf9bdc)" uri="spotify:track:5XeFesFbtLpXzIVDNQP22n" Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=debug msg="requested aes key for file 65e016df53012c00d63f36e72741de66e4cf9bdc, gid: 5XeFesFbtLpXzIVDNQP22n" Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=debug msg="fetched first chunk of 13, total size is 6686124 bytes" uri="spotify:track:5XeFesFbtLpXzIVDNQP22n" Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:5XeFesFbtLpXzIVDNQP22n" Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" 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 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=info msg="loaded track \"I Wanna Be Yours\" (paused: false, position: 0ms, duration: 183956ms, prefetched: false)" uri="spotify:track:5XeFesFbtLpXzIVDNQP22n" Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=debug msg="fetched chunk 1/12, size: 524288" uri="spotify:track:5XeFesFbtLpXzIVDNQP22n" Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=debug msg="fetched chunk 3/12, size: 524288" uri="spotify:track:5XeFesFbtLpXzIVDNQP22n" Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=debug msg="fetched chunk 2/12, size: 524288" uri="spotify:track:5XeFesFbtLpXzIVDNQP22n" Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=trace msg="scheduling prefetch in 154s" Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=trace msg="emitting websocket event: metadata" Oct 13 12:52:02 volumio volumio[894]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5XeFesFbtLpXzIVDNQP22n","name":"I Wanna Be Yours","artist_names":["Arctic Monkeys"],"album_name":"AM","album_cover_url":"https://i.scdn.co/image/ab67616d00001e024ae1c4c5c45aabe565499163","position":0,"duration":183956,"release_date":"year:2013 month:9 day:9","track_number":12,"disc_number":1}} Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 12:52:02 volumio go-librespot[1221]: time="2024-10-13T12:52:02+02:00" level=trace msg="emitting websocket event: playing" Oct 13 12:52:02 volumio volumio[894]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5XeFesFbtLpXzIVDNQP22n","play_origin":"go-librespot"}} Oct 13 12:52:02 volumio volumio[894]: SPOTIFY: PUSH STATE SPOTIFY Oct 13 12:52:02 volumio volumio[894]: SPOTIFY: {"status":"play","service":"spop","title":"I Wanna Be Yours","artist":"Arctic Monkeys","album":"AM","albumart":"https://i.scdn.co/image/ab67616d00001e024ae1c4c5c45aabe565499163","uri":"spotify:track:5XeFesFbtLpXzIVDNQP22n","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 13 12:52:02 volumio volumio[894]: info: CoreCommandRouter::servicePushState Oct 13 12:52:02 volumio volumio[894]: info: CorePlayQueue::getTrack 0 Oct 13 12:52:02 volumio volumio[894]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"I Wanna Be Yours","artist":"Arctic Monkeys","album":"AM","albumart":"https://i.scdn.co/image/ab67616d00001e024ae1c4c5c45aabe565499163","uri":"spotify:track:5XeFesFbtLpXzIVDNQP22n","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 13 12:52:02 volumio volumio[894]: verbose: CURRENT POSITION 0 Oct 13 12:52:02 volumio volumio[894]: info: CoreStateMachine::syncState stateService play Oct 13 12:52:02 volumio volumio[894]: info: CoreStateMachine::syncState currentStatus stop Oct 13 12:52:03 volumio volumio[894]: SPOTIFY: PUSH STATE SPOTIFY Oct 13 12:52:03 volumio volumio[894]: SPOTIFY: {"status":"play","service":"spop","title":"I Wanna Be Yours","artist":"Arctic Monkeys","album":"AM","albumart":"https://i.scdn.co/image/ab67616d00001e024ae1c4c5c45aabe565499163","uri":"spotify:track:5XeFesFbtLpXzIVDNQP22n","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 13 12:52:03 volumio volumio[894]: info: CoreCommandRouter::servicePushState Oct 13 12:52:03 volumio volumio[894]: info: CorePlayQueue::getTrack 0 Oct 13 12:52:03 volumio volumio[894]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"I Wanna Be Yours","artist":"Arctic Monkeys","album":"AM","albumart":"https://i.scdn.co/image/ab67616d00001e024ae1c4c5c45aabe565499163","uri":"spotify:track:5XeFesFbtLpXzIVDNQP22n","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 13 12:52:03 volumio volumio[894]: verbose: CURRENT POSITION 0 Oct 13 12:52:03 volumio volumio[894]: info: CoreStateMachine::syncState stateService play Oct 13 12:52:03 volumio volumio[894]: info: CoreStateMachine::syncState currentStatus play Oct 13 12:52:03 volumio volumio[894]: info: Received an update from plugin. extracting info from payload Oct 13 12:52:03 volumio volumio[894]: info: CoreStateMachine::pushState Oct 13 12:52:03 volumio volumio[894]: info: CorePlayQueue::getTrack 0 Oct 13 12:52:03 volumio volumio[894]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 12:52:03 volumio volumio[894]: info: CoreCommandRouter::volumioPushState Oct 13 12:52:03 volumio volumio[894]: info: CoreStateMachine::pushState Oct 13 12:52:03 volumio volumio[894]: info: CorePlayQueue::getTrack 0 Oct 13 12:52:03 volumio volumio[894]: info: CoreCommandRouter::volumioPushState Oct 13 12:52:03 volumio volumio[894]: info: [LastFM] Current track has sufficient metadata: title (I Wanna Be Yours) and artist (Arctic Monkeys) passed on explicitly Oct 13 12:52:03 volumio volumio[894]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 12:52:03 volumio volumio[894]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 12:52:03 volumio volumio[894]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"I Wanna Be Yours","mbid":"a1ff202f-f271-4646-9aac-ba7c98e3a50c","url":"https://www.last.fm/music/Arctic+Monkeys/_/I+Wanna+Be+Yours","duration":"55000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"1892832","playcount":"27992057","artist":{"name":"Arctic Monkeys","mbid":"ada7a83c-e3e1-40f1-93f9-3e73dbc9298a","url":"https://www.last.fm/music/Arctic+Monkeys"},"album":{"@":{"position":"12"},"artist":"Arctic Monkeys","title":"AM","mbid":"bf584cf2-dc33-433e-b8b2-b85578822726","url":"https://www.last.fm/music/Arctic+Monkeys/AM","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/f579e414e20f40969185e41182d72472.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/f579e414e20f40969185e41182d72472.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/f579e414e20f40969185e41182d72472.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/f579e414e20f40969185e41182d72472.png","@":{"size":"extralarge"}}]},"userplaycount":"6","userloved":"0","toptags":{"tag":[{"name":"indie rock","url":"https://www.last.fm/tag/indie+rock"},{"name":"alternative","url":"https://www.last.fm/tag/alternative"},{"name":"indie","url":"https://www.last.fm/tag/indie"},{"name":"british","url":"https://www.last.fm/tag/british"},{"name":"sexy","url":"https://www.last.fm/tag/sexy"}]},"wiki":{"published":"08 Feb 2014, 19:55","summary":"\"I Wanna Be Yours\" is an adaptation of a poem by John Cooper Clarke, an English performance poet who first became famous during the punk rock era of the late 1970s. Clarke's work has been influential to lead-singer Alex Turner, who takes inspiration for lyrics from his poems. The Clarke poem \"Out of Control Fairground\" was featured in the single sleeve for Fluorescent Adolescent. Read more on Last.fm.","content":"\"I Wanna Be Yours\" is an adaptation of a poem by John Cooper Clarke, an English performance poet who first became famous during the punk rock era of the late 1970s. Clarke's work has been influential to lead-singer Alex Turner, who takes inspiration for lyrics from his poems. The Clarke poem \"Out of Control Fairground\" was featured in the single sleeve for Fluorescent Adolescent. Read more on Last.fm. User-contributed text is available under the Creative Commons By-SA License; additional terms may apply."}}} Oct 13 12:52:08 volumio kernel: hwmon hwmon1: Voltage normalised Oct 13 12:52:13 volumio kernel: hwmon hwmon1: Undervoltage detected! Oct 13 12:52:17 volumio volumio[894]: Searching all installed plugins Oct 13 12:52:17 volumio volumio[894]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 13 12:52:17 volumio volumio[894]: info: CoreCommandRouter::executeOnPlugin: , search Oct 13 12:52:17 volumio volumio[894]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 13 12:52:17 volumio volumio[894]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Oct 13 12:52:17 volumio volumio[894]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Oct 13 12:52:17 volumio volumio[894]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Oct 13 12:52:17 volumio volumio[894]: info: CoreCommandRouter::executeOnPlugin: webradio , search Oct 13 12:52:17 volumio volumio[894]: info: CoreCommandRouter::executeOnPlugin: calmradio , search Oct 13 12:52:17 volumio volumio[894]: info: [1728816737512] ControllerCalmRadio::searchCategories Oct 13 12:52:17 volumio volumio[894]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 13 12:52:17 volumio volumio[894]: TypeError: Cannot read property 'cats' of undefined Oct 13 12:52:17 volumio volumio[894]: at ControllerCalmRadio.searchCategories (/data/plugins/music_service/calmradio/index.js:615:42) Oct 13 12:52:17 volumio volumio[894]: at ControllerCalmRadio.search (/data/plugins/music_service/calmradio/index.js:665:28) Oct 13 12:52:17 volumio volumio[894]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1083:32) Oct 13 12:52:17 volumio volumio[894]: at CoreMusicLibrary.searchOnPlugin (/volumio/app/musiclibrary.js:668:44) Oct 13 12:52:17 volumio volumio[894]: at CoreMusicLibrary.search (/volumio/app/musiclibrary.js:455:27) Oct 13 12:52:17 volumio volumio[894]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:485:44) Oct 13 12:52:17 volumio volumio[894]: at Socket.emit (events.js:315:20) Oct 13 12:52:17 volumio volumio[894]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Oct 13 12:52:17 volumio volumio[894]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Oct 13 12:52:17 volumio volumio[894]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 13 12:52:17 volumio go-librespot[1221]: time="2024-10-13T12:52:17+02:00" level=debug msg="fetched chunk 4/12, size: 524288" uri="spotify:track:5XeFesFbtLpXzIVDNQP22n" Oct 13 12:52:17 volumio sudo[3081]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-13 12:51 Oct 13 12:52:17 volumio sudo[3081]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"