-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Mon 2024-04-29 14:41:24 CEST. --
Apr 29 14:40:16 motivo volumio[929]: info: CorePlayQueue::getTrack 12
Apr 29 14:40:16 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:16 motivo volumio[929]: info: Prefetching next song
Apr 29 14:40:20 motivo go-librespot[3035]: time="2024-04-29T14:40:20+02:00" level=trace msg="emitting websocket event: not_playing"
Apr 29 14:40:20 motivo go-librespot[3035]: time="2024-04-29T14:40:20+02:00" level=debug msg="loading track spotify:track:3ChFv9qfFUg6HpG0UeU9WJ (paused: true, position: 0ms)"
Apr 29 14:40:20 motivo volumio[929]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:3ChFv9qfFUg6HpG0UeU9WJ","play_origin":"go-librespot"}}
Apr 29 14:40:20 motivo volumio[929]: error: Failed to decode event: not_playing
Apr 29 14:40:20 motivo go-librespot[3035]: time="2024-04-29T14:40:20+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 29 14:40:20 motivo go-librespot[3035]: time="2024-04-29T14:40:20+02:00" level=trace msg="emitting websocket event: will_play"
Apr 29 14:40:20 motivo volumio[929]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3ChFv9qfFUg6HpG0UeU9WJ","play_origin":"go-librespot"}}
Apr 29 14:40:20 motivo go-librespot[3035]: time="2024-04-29T14:40:20+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:3ChFv9qfFUg6HpG0UeU9WJ"
Apr 29 14:40:20 motivo go-librespot[3035]: time="2024-04-29T14:40:20+02:00" level=debug msg="requested aes key for file 1f24a94a9bb7a1c115c1d6401fcd3ce7912b4f69, gid: 3ChFv9qfFUg6HpG0UeU9WJ"
Apr 29 14:40:20 motivo volumio[929]: 0+0 records in
Apr 29 14:40:20 motivo volumio[929]: 0+0 records out
Apr 29 14:40:20 motivo volumio[929]: 0 bytes copied, 0.000277995 s, 0.0 kB/s
Apr 29 14:40:20 motivo volumio[929]: info: camilladsp spawned new process with pid 3773, instance 1, run: true
Apr 29 14:40:21 motivo go-librespot[3035]: time="2024-04-29T14:40:21+02:00" level=debug msg="fetched first chunk of 26, total size is 13403332 bytes"
Apr 29 14:40:21 motivo go-librespot[3035]: time="2024-04-29T14:40:21+02:00" level=trace msg="seek to 0ms (diff: -23ms, samples: 0, bytes: 3475)"
Apr 29 14:40:21 motivo volumio[929]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Apr 29 14:40:21 motivo volumio[929]: info: FusionDsp - ---- read samplerate from file: 44100
Apr 29 14:40:21 motivo volumio[929]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Apr 29 14:40:21 motivo go-librespot[3035]: time="2024-04-29T14:40:21+02:00" level=info msg="loaded track \"Got Groove\" (uri: spotify:track:3ChFv9qfFUg6HpG0UeU9WJ, paused: true, position: 0ms, duration: 334000ms)"
Apr 29 14:40:21 motivo volumio[929]: info: FusionDsp - eq1:
Apr 29 14:40:21 motivo volumio[929]: type: Biquad
Apr 29 14:40:21 motivo volumio[929]: parameters:
Apr 29 14:40:21 motivo volumio[929]: type: Lowshelf
Apr 29 14:40:21 motivo volumio[929]: freq: 185
Apr 29 14:40:21 motivo volumio[929]: q: 0.82
Apr 29 14:40:21 motivo volumio[929]: gain: 0
Apr 29 14:40:21 motivo volumio[929]: eq2:
Apr 29 14:40:21 motivo volumio[929]: type: Biquad
Apr 29 14:40:21 motivo volumio[929]: parameters:
Apr 29 14:40:21 motivo volumio[929]: type: Peaking
Apr 29 14:40:21 motivo volumio[929]: freq: 1300
Apr 29 14:40:21 motivo volumio[929]: q: 0.4
Apr 29 14:40:21 motivo volumio[929]: gain: 0
Apr 29 14:40:21 motivo volumio[929]: eq3:
Apr 29 14:40:21 motivo volumio[929]: type: Biquad
Apr 29 14:40:21 motivo volumio[929]: parameters:
Apr 29 14:40:21 motivo volumio[929]: type: Highshelf
Apr 29 14:40:21 motivo volumio[929]: freq: 5500
Apr 29 14:40:21 motivo volumio[929]: q: 0.82
Apr 29 14:40:21 motivo volumio[929]: gain: 0
Apr 29 14:40:21 motivo volumio[929]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Apr 29 14:40:21 motivo volumio[929]: 0+0 records in
Apr 29 14:40:21 motivo volumio[929]: 0+0 records out
Apr 29 14:40:21 motivo volumio[929]: 0 bytes copied, 0.000201514 s, 0.0 kB/s
Apr 29 14:40:21 motivo volumio[929]: info: camilladsp spawned new process with pid 3784, instance 1, run: true
Apr 29 14:40:21 motivo go-librespot[3035]: time="2024-04-29T14:40:21+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 29 14:40:21 motivo go-librespot[3035]: time="2024-04-29T14:40:21+02:00" level=trace msg="emitting websocket event: metadata"
Apr 29 14:40:21 motivo go-librespot[3035]: time="2024-04-29T14:40:21+02:00" level=trace msg="emitting websocket event: stopped"
Apr 29 14:40:21 motivo volumio[929]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3ChFv9qfFUg6HpG0UeU9WJ","name":"Got Groove","artist_names":["Brine"],"album_name":"The Way I Do It - EP","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02374b5d982320441ca19e4a97","position":0,"duration":334000,"release_date":"year:2023 month:12 day:29","track_number":2,"disc_number":1}}
Apr 29 14:40:21 motivo volumio[929]: SPOTIFY: received: {"type":"stopped","data":{"play_origin":"go-librespot"}}
Apr 29 14:40:21 motivo volumio[929]: SPOTIFY: PUSH STATE SPOTIFY
Apr 29 14:40:21 motivo volumio[929]: SPOTIFY: {"status":"stop","service":"spop","title":"Got Groove","artist":"Brine","album":"The Way I Do It - EP","albumart":"https://i.scdn.co/image/ab67616d00001e02374b5d982320441ca19e4a97","uri":"spotify:track:3ChFv9qfFUg6HpG0UeU9WJ","trackType":"spotify","seek":0,"duration":334,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 29 14:40:21 motivo volumio[929]: info: CoreCommandRouter::servicePushState
Apr 29 14:40:21 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:21 motivo volumio[929]: info: CorePlayQueue::getTrack 12
Apr 29 14:40:21 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:21 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:21 motivo volumio[929]: info: CorePlayQueue::getTrack 12
Apr 29 14:40:21 motivo volumio[929]: verbose: STATE SERVICE {"status":"stop","service":"spop","title":"Got Groove","artist":"Brine","album":"The Way I Do It - EP","albumart":"https://i.scdn.co/image/ab67616d00001e02374b5d982320441ca19e4a97","uri":"spotify:track:3ChFv9qfFUg6HpG0UeU9WJ","trackType":"spotify","seek":0,"duration":334,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 29 14:40:21 motivo volumio[929]: verbose: CURRENT POSITION 12
Apr 29 14:40:21 motivo volumio[929]: info: CoreStateMachine::syncState stateService stop
Apr 29 14:40:21 motivo volumio[929]: info: CoreStateMachine::syncState currentStatus play
Apr 29 14:40:21 motivo volumio[929]: info: CoreStateMachine::play index undefined
Apr 29 14:40:21 motivo volumio[929]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 29 14:40:21 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:21 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:21 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:21 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:21 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:21 motivo volumio[929]: info: CoreStateMachine::startPlaybackTimer
Apr 29 14:40:21 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:21 motivo volumio[929]: info: [1714394421680] ControllerSpotify::clearAddPlayTrack
Apr 29 14:40:21 motivo volumio[929]: info: Sending Spotify command with payload to local API: /player/play
Apr 29 14:40:21 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:21 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:21 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:21 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:21 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:21 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:21 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:21 motivo volumio[929]: info: MCU Signalled Playback Inactive
Apr 29 14:40:21 motivo go-librespot[3035]: time="2024-04-29T14:40:21+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 29 14:40:21 motivo go-librespot[3035]: time="2024-04-29T14:40:21+02:00" level=trace msg="emitting websocket event: paused"
Apr 29 14:40:21 motivo volumio[929]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:3ChFv9qfFUg6HpG0UeU9WJ","play_origin":"go-librespot"}}
Apr 29 14:40:21 motivo volumio[929]: SPOTIFY: PUSH STATE SPOTIFY
Apr 29 14:40:21 motivo volumio[929]: 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}
Apr 29 14:40:21 motivo volumio[929]: info: CoreCommandRouter::servicePushState
Apr 29 14:40:21 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:21 motivo volumio[929]: 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}
Apr 29 14:40:21 motivo volumio[929]: verbose: CURRENT POSITION 13
Apr 29 14:40:21 motivo volumio[929]: info: CoreStateMachine::syncState stateService pause
Apr 29 14:40:21 motivo volumio[929]: info: CoreStateMachine::syncState currentStatus stop
Apr 29 14:40:21 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:21 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:21 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:21 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:21 motivo go-librespot[3035]: time="2024-04-29T14:40:21+02:00" level=debug msg="fetched chunk 1/25, size: 524288"
Apr 29 14:40:21 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:22 motivo go-librespot[3035]: time="2024-04-29T14:40:22+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Apr 29 14:40:22 motivo go-librespot[3035]: time="2024-04-29T14:40:22+02:00" level=debug msg="loading track spotify:track:6VltkMtZhr91H9Nmyi1mbM (paused: false, position: 1ms)"
Apr 29 14:40:22 motivo go-librespot[3035]: time="2024-04-29T14:40:22+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 29 14:40:22 motivo go-librespot[3035]: time="2024-04-29T14:40:22+02:00" level=trace msg="emitting websocket event: will_play"
Apr 29 14:40:22 motivo volumio[929]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6VltkMtZhr91H9Nmyi1mbM","play_origin":"go-librespot"}}
Apr 29 14:40:22 motivo go-librespot[3035]: time="2024-04-29T14:40:22+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:6VltkMtZhr91H9Nmyi1mbM"
Apr 29 14:40:22 motivo go-librespot[3035]: time="2024-04-29T14:40:22+02:00" level=debug msg="requested aes key for file 3f68c13be8aeaf1db8c81b7addb95a1911e27d7c, gid: 6VltkMtZhr91H9Nmyi1mbM"
Apr 29 14:40:22 motivo go-librespot[3035]: time="2024-04-29T14:40:22+02:00" level=debug msg="fetched chunk 2/25, size: 524288"
Apr 29 14:40:22 motivo go-librespot[3035]: time="2024-04-29T14:40:22+02:00" level=debug msg="fetched chunk 3/25, size: 524288"
Apr 29 14:40:23 motivo go-librespot[3035]: time="2024-04-29T14:40:23+02:00" level=debug msg="fetched first chunk of 20, total size is 10040984 bytes"
Apr 29 14:40:23 motivo go-librespot[3035]: time="2024-04-29T14:40:23+02:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)"
Apr 29 14:40:23 motivo volumio[929]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Apr 29 14:40:23 motivo volumio[929]: info: FusionDsp - ---- read samplerate from file: 44100
Apr 29 14:40:23 motivo volumio[929]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Apr 29 14:40:23 motivo go-librespot[3035]: time="2024-04-29T14:40:23+02:00" level=info msg="loaded track \"Love Reaction (You Give Me Vibrations)\" (uri: spotify:track:6VltkMtZhr91H9Nmyi1mbM, paused: false, position: 1ms, duration: 268982ms)"
Apr 29 14:40:23 motivo volumio[929]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Apr 29 14:40:23 motivo volumio[929]: info: FusionDsp - ---- read samplerate from file: 44100
Apr 29 14:40:23 motivo volumio[929]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Apr 29 14:40:23 motivo volumio[929]: info: FusionDsp - eq1:
Apr 29 14:40:23 motivo volumio[929]: type: Biquad
Apr 29 14:40:23 motivo volumio[929]: parameters:
Apr 29 14:40:23 motivo volumio[929]: type: Lowshelf
Apr 29 14:40:23 motivo volumio[929]: freq: 185
Apr 29 14:40:23 motivo volumio[929]: q: 0.82
Apr 29 14:40:23 motivo volumio[929]: gain: 0
Apr 29 14:40:23 motivo volumio[929]: eq2:
Apr 29 14:40:23 motivo volumio[929]: type: Biquad
Apr 29 14:40:23 motivo volumio[929]: parameters:
Apr 29 14:40:23 motivo volumio[929]: type: Peaking
Apr 29 14:40:23 motivo volumio[929]: freq: 1300
Apr 29 14:40:23 motivo volumio[929]: q: 0.4
Apr 29 14:40:23 motivo volumio[929]: gain: 0
Apr 29 14:40:23 motivo volumio[929]: eq3:
Apr 29 14:40:23 motivo volumio[929]: type: Biquad
Apr 29 14:40:23 motivo volumio[929]: parameters:
Apr 29 14:40:23 motivo volumio[929]: type: Highshelf
Apr 29 14:40:23 motivo volumio[929]: freq: 5500
Apr 29 14:40:23 motivo volumio[929]: q: 0.82
Apr 29 14:40:23 motivo volumio[929]: gain: 0
Apr 29 14:40:23 motivo volumio[929]: info: FusionDsp - eq1:
Apr 29 14:40:23 motivo volumio[929]: type: Biquad
Apr 29 14:40:23 motivo volumio[929]: parameters:
Apr 29 14:40:23 motivo volumio[929]: type: Lowshelf
Apr 29 14:40:23 motivo volumio[929]: freq: 185
Apr 29 14:40:23 motivo volumio[929]: q: 0.82
Apr 29 14:40:23 motivo volumio[929]: gain: 0
Apr 29 14:40:23 motivo volumio[929]: eq2:
Apr 29 14:40:23 motivo volumio[929]: type: Biquad
Apr 29 14:40:23 motivo volumio[929]: parameters:
Apr 29 14:40:23 motivo volumio[929]: type: Peaking
Apr 29 14:40:23 motivo volumio[929]: freq: 1300
Apr 29 14:40:23 motivo volumio[929]: q: 0.4
Apr 29 14:40:23 motivo volumio[929]: gain: 0
Apr 29 14:40:23 motivo volumio[929]: eq3:
Apr 29 14:40:23 motivo volumio[929]: type: Biquad
Apr 29 14:40:23 motivo volumio[929]: parameters:
Apr 29 14:40:23 motivo volumio[929]: type: Highshelf
Apr 29 14:40:23 motivo volumio[929]: freq: 5500
Apr 29 14:40:23 motivo volumio[929]: q: 0.82
Apr 29 14:40:23 motivo volumio[929]: gain: 0
Apr 29 14:40:23 motivo volumio[929]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Apr 29 14:40:23 motivo volumio[929]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Apr 29 14:40:23 motivo go-librespot[3035]: time="2024-04-29T14:40:23+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 29 14:40:23 motivo go-librespot[3035]: time="2024-04-29T14:40:23+02:00" level=trace msg="emitting websocket event: metadata"
Apr 29 14:40:23 motivo volumio[929]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6VltkMtZhr91H9Nmyi1mbM","name":"Love Reaction (You Give Me Vibrations)","artist_names":["Brine","Franz K"],"album_name":"Outer Space Grooves","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0202486f7f52d481aeca4be8c7","position":1,"duration":268982,"release_date":"year:2023 month:7 day:28","track_number":2,"disc_number":1}}
Apr 29 14:40:23 motivo go-librespot[3035]: time="2024-04-29T14:40:23+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 29 14:40:23 motivo go-librespot[3035]: time="2024-04-29T14:40:23+02:00" level=trace msg="emitting websocket event: playing"
Apr 29 14:40:23 motivo volumio[929]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6VltkMtZhr91H9Nmyi1mbM","play_origin":"go-librespot"}}
Apr 29 14:40:23 motivo volumio[929]: SPOTIFY: PUSH STATE SPOTIFY
Apr 29 14:40:23 motivo volumio[929]: SPOTIFY: {"status":"play","service":"spop","title":"Love Reaction (You Give Me Vibrations)","artist":"Brine, Franz K","album":"Outer Space Grooves","albumart":"https://i.scdn.co/image/ab67616d00001e0202486f7f52d481aeca4be8c7","uri":"spotify:track:6VltkMtZhr91H9Nmyi1mbM","trackType":"spotify","seek":1,"duration":268,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 29 14:40:23 motivo volumio[929]: info: CoreCommandRouter::servicePushState
Apr 29 14:40:23 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:23 motivo volumio[929]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Love Reaction (You Give Me Vibrations)","artist":"Brine, Franz K","album":"Outer Space Grooves","albumart":"https://i.scdn.co/image/ab67616d00001e0202486f7f52d481aeca4be8c7","uri":"spotify:track:6VltkMtZhr91H9Nmyi1mbM","trackType":"spotify","seek":1,"duration":268,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 29 14:40:23 motivo volumio[929]: verbose: CURRENT POSITION 13
Apr 29 14:40:23 motivo volumio[929]: info: CoreStateMachine::syncState stateService play
Apr 29 14:40:23 motivo volumio[929]: info: CoreStateMachine::syncState currentStatus stop
Apr 29 14:40:23 motivo go-librespot[3035]: time="2024-04-29T14:40:23+02:00" level=debug msg="fetched chunk 1/19, size: 524288"
Apr 29 14:40:23 motivo go-librespot[3035]: time="2024-04-29T14:40:23+02:00" level=debug msg="fetched chunk 2/19, size: 524288"
Apr 29 14:40:23 motivo go-librespot[3035]: time="2024-04-29T14:40:23+02:00" level=debug msg="fetched chunk 3/19, size: 62930"
Apr 29 14:40:24 motivo volumio[929]: SPOTIFY: PUSH STATE SPOTIFY
Apr 29 14:40:24 motivo volumio[929]: SPOTIFY: {"status":"play","service":"spop","title":"Love Reaction (You Give Me Vibrations)","artist":"Brine, Franz K","album":"Outer Space Grooves","albumart":"https://i.scdn.co/image/ab67616d00001e0202486f7f52d481aeca4be8c7","uri":"spotify:track:6VltkMtZhr91H9Nmyi1mbM","trackType":"spotify","seek":1,"duration":268,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 29 14:40:24 motivo volumio[929]: info: CoreCommandRouter::servicePushState
Apr 29 14:40:24 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:24 motivo volumio[929]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Love Reaction (You Give Me Vibrations)","artist":"Brine, Franz K","album":"Outer Space Grooves","albumart":"https://i.scdn.co/image/ab67616d00001e0202486f7f52d481aeca4be8c7","uri":"spotify:track:6VltkMtZhr91H9Nmyi1mbM","trackType":"spotify","seek":1,"duration":268,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Apr 29 14:40:24 motivo volumio[929]: verbose: CURRENT POSITION 13
Apr 29 14:40:24 motivo volumio[929]: info: CoreStateMachine::syncState stateService play
Apr 29 14:40:24 motivo volumio[929]: info: CoreStateMachine::syncState currentStatus play
Apr 29 14:40:24 motivo volumio[929]: info: Received an update from plugin. extracting info from payload
Apr 29 14:40:24 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:24 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:24 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:24 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:24 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:24 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:24 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:24 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:24 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:24 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:24 motivo volumio[929]: info: MCU Signalled Playback Active
Apr 29 14:40:30 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:30 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:30 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:30 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:30 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:30 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:30 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 1
Apr 29 14:40:30 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:30 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:30 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:30 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:30 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:30 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:30 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 2
Apr 29 14:40:30 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 1
Apr 29 14:40:30 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 2
Apr 29 14:40:30 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: false
Apr 29 14:40:30 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:30 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:30 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:30 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:30 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:30 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:30 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 3
Apr 29 14:40:30 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 1
Apr 29 14:40:30 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 3
Apr 29 14:40:30 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: true
Apr 29 14:40:30 motivo volumio[929]: info: Setting Spotify Volume from Volumio: 3
Apr 29 14:40:30 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:30 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:30 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:30 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:30 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:30 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:30 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 3
Apr 29 14:40:31 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:31 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:31 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:31 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:31 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:31 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:31 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 3
Apr 29 14:40:31 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:31 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:31 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:31 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:31 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:31 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:31 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 6
Apr 29 14:40:31 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 3
Apr 29 14:40:31 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 6
Apr 29 14:40:31 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: true
Apr 29 14:40:31 motivo volumio[929]: info: Setting Spotify Volume from Volumio: 6
Apr 29 14:40:31 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:31 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:31 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:31 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:31 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:31 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:31 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 7
Apr 29 14:40:31 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 6
Apr 29 14:40:31 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 7
Apr 29 14:40:31 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: false
Apr 29 14:40:31 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:31 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:31 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:31 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:31 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:31 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:31 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 7
Apr 29 14:40:31 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 6
Apr 29 14:40:31 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 7
Apr 29 14:40:31 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: false
Apr 29 14:40:31 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:31 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:31 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:31 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:31 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:31 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:31 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10
Apr 29 14:40:31 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 6
Apr 29 14:40:31 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 10
Apr 29 14:40:31 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: true
Apr 29 14:40:31 motivo volumio[929]: info: Setting Spotify Volume from Volumio: 10
Apr 29 14:40:31 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:31 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:31 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:31 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:32 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:32 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 10
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 11
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: false
Apr 29 14:40:32 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:32 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:32 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:32 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:32 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:32 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 10
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 11
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: false
Apr 29 14:40:32 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:32 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:32 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:32 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:32 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:32 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 15
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 10
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 15
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: true
Apr 29 14:40:32 motivo volumio[929]: info: Setting Spotify Volume from Volumio: 15
Apr 29 14:40:32 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:32 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:32 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:32 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:32 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:32 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 15
Apr 29 14:40:32 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:32 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:32 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:32 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:32 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:32 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 15
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 18
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: true
Apr 29 14:40:32 motivo volumio[929]: info: Setting Spotify Volume from Volumio: 18
Apr 29 14:40:32 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:32 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:32 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:32 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:32 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:32 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 21
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 18
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 21
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: true
Apr 29 14:40:32 motivo volumio[929]: info: Setting Spotify Volume from Volumio: 21
Apr 29 14:40:32 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:32 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:32 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:32 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:32 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:32 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 21
Apr 29 14:40:33 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:33 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:33 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:33 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:33 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:33 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 21
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 24
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: true
Apr 29 14:40:33 motivo volumio[929]: info: Setting Spotify Volume from Volumio: 24
Apr 29 14:40:33 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:33 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:33 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:33 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:33 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:33 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 24
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 27
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: true
Apr 29 14:40:33 motivo volumio[929]: info: Setting Spotify Volume from Volumio: 27
Apr 29 14:40:33 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:33 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:33 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:33 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:33 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27
Apr 29 14:40:33 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:33 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:33 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:33 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:33 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:33 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 27
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 30
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: true
Apr 29 14:40:33 motivo volumio[929]: info: Setting Spotify Volume from Volumio: 30
Apr 29 14:40:33 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:33 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:33 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:33 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:33 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:33 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 30
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 31
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: false
Apr 29 14:40:33 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:33 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:33 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:33 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:33 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:33 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 30
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 34
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: true
Apr 29 14:40:33 motivo volumio[929]: info: Setting Spotify Volume from Volumio: 34
Apr 29 14:40:33 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:33 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:33 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:33 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:33 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:33 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 37
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 34
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 37
Apr 29 14:40:33 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: true
Apr 29 14:40:33 motivo volumio[929]: info: Setting Spotify Volume from Volumio: 37
Apr 29 14:40:34 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:34 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:34 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:34 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:34 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 37
Apr 29 14:40:34 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:34 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:34 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:34 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:34 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:34 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 39
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 37
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 39
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: true
Apr 29 14:40:34 motivo volumio[929]: info: Setting Spotify Volume from Volumio: 39
Apr 29 14:40:34 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:34 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:34 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:34 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:34 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:34 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 39
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 40
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: false
Apr 29 14:40:34 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:34 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:34 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:34 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:34 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 39
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 40
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: false
Apr 29 14:40:34 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:34 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:34 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:34 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:34 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:34 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 39
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 43
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: true
Apr 29 14:40:34 motivo volumio[929]: info: Setting Spotify Volume from Volumio: 43
Apr 29 14:40:34 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:34 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:34 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:34 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:34 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:34 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 43
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 44
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: false
Apr 29 14:40:34 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:34 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:34 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:34 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:34 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:34 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 43
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 44
Apr 29 14:40:34 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: false
Apr 29 14:40:35 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:35 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:35 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:35 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:35 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:35 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:35 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 47
Apr 29 14:40:35 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 43
Apr 29 14:40:35 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 47
Apr 29 14:40:35 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: true
Apr 29 14:40:35 motivo volumio[929]: info: Setting Spotify Volume from Volumio: 47
Apr 29 14:40:35 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:35 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:35 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:35 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:35 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:35 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 47
Apr 29 14:40:35 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:35 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:35 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:40:35 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:35 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:35 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:35 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 49
Apr 29 14:40:35 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 47
Apr 29 14:40:35 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 49
Apr 29 14:40:35 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: true
Apr 29 14:40:35 motivo volumio[929]: info: Setting Spotify Volume from Volumio: 49
Apr 29 14:40:35 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:40:35 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:40:35 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:40:35 motivo volumio[929]: info: Signalling Playback active due to playback status change
Apr 29 14:40:35 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:40:35 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 49
Apr 29 14:40:35 motivo go-librespot[3035]: time="2024-04-29T14:40:35+02:00" level=debug msg="fetched chunk 4/19, size: 524288"
Apr 29 14:40:36 motivo volumio[929]: SPOTIFY: SETTING SPOTIFY VOLUME 49
Apr 29 14:40:36 motivo volumio[929]: info: Sending Spotify command with payload to local API: /player/volume
Apr 29 14:40:36 motivo go-librespot[3035]: time="2024-04-29T14:40:36+02:00" level=debug msg="update volume to 32112/65535"
Apr 29 14:40:37 motivo go-librespot[3035]: time="2024-04-29T14:40:37+02:00" level=debug msg="put connect state because VOLUME_CHANGED"
Apr 29 14:40:37 motivo go-librespot[3035]: time="2024-04-29T14:40:37+02:00" level=trace msg="emitting websocket event: volume"
Apr 29 14:40:37 motivo volumio[929]: SPOTIFY: received: {"type":"volume","data":{"value":49,"max":100}}
Apr 29 14:40:37 motivo volumio[929]: SPOTIFY: RECEIVED SPOTIFY VOLUME 49
Apr 29 14:40:41 motivo volumio[929]: Searching plugin music_service/spop
Apr 29 14:40:41 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: spop , search
Apr 29 14:40:42 motivo volumio[929]: info: All search sources collected, pushing search results
Apr 29 14:40:42 motivo volumio[929]: Searching plugin music_service/spop
Apr 29 14:40:42 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: spop , search
Apr 29 14:40:43 motivo volumio[929]: info: All search sources collected, pushing search results
Apr 29 14:40:45 motivo volumio[929]: Searching plugin music_service/spop
Apr 29 14:40:45 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: spop , search
Apr 29 14:40:45 motivo volumio[929]: info: All search sources collected, pushing search results
Apr 29 14:40:46 motivo volumio[929]: Searching plugin music_service/spop
Apr 29 14:40:46 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: spop , search
Apr 29 14:40:47 motivo volumio[929]: info: All search sources collected, pushing search results
Apr 29 14:40:47 motivo volumio[929]: Searching plugin music_service/spop
Apr 29 14:40:47 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: spop , search
Apr 29 14:40:47 motivo volumio[929]: info: All search sources collected, pushing search results
Apr 29 14:40:49 motivo go-librespot[3035]: time="2024-04-29T14:40:49+02:00" level=debug msg="fetched chunk 5/19, size: 524288"
Apr 29 14:40:52 motivo volumio[929]: Searching plugin music_service/spop
Apr 29 14:40:52 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: spop , search
Apr 29 14:40:52 motivo volumio[929]: info: All search sources collected, pushing search results
Apr 29 14:40:55 motivo volumio[929]: Searching plugin music_service/spop
Apr 29 14:40:55 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: spop , search
Apr 29 14:40:56 motivo volumio[929]: Searching plugin music_service/spop
Apr 29 14:40:56 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: spop , search
Apr 29 14:40:56 motivo volumio[929]: info: All search sources collected, pushing search results
Apr 29 14:40:57 motivo volumio[929]: info: All search sources collected, pushing search results
Apr 29 14:41:02 motivo go-librespot[3035]: time="2024-04-29T14:41:02+02:00" level=debug msg="fetched chunk 6/19, size: 524288"
Apr 29 14:41:03 motivo go-librespot[3035]: time="2024-04-29T14:41:03+02:00" level=debug msg="vorbis: corrupt or missing data in bitstream"
Apr 29 14:41:03 motivo go-librespot[3035]: panic: runtime error: slice bounds out of range [65703:62930]
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 194623 [running]:
Apr 29 14:41:03 motivo go-librespot[3035]: panic({0x5db090, 0x25a2150})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/panic.go:987 +0x414 fp=0x2735da4 sp=0x2735d48 pc=0x4ee28
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goPanicSliceB(0x100a7, 0xf5d2)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/panic.go:153 +0xa4 fp=0x2735dc4 sp=0x2735da4 pc=0x4ce84
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/audio.(*HttpChunkedReader).ReadAt(0x39f82a0, {0x2291b30, 0x1000, 0x7fffffff}, 0x1900a7)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:218 +0x2b4 fp=0x2735e24 sp=0x2735dc4 pc=0x45b818
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/audio.(*Decryptor).ReadAt(0x240e160, {0x2291b30, 0x1000, 0x7fffffff}, 0x1900a7)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/audio/decryptor.go:49 +0x224 fp=0x2735e80 sp=0x2735e24 pc=0x45be34
Apr 29 14:41:03 motivo go-librespot[3035]: io.(*SectionReader).Read(0x437c180, {0x2291b30, 0x1000, 0x7fffffff})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/io/io.go:513 +0xdc fp=0x2735ea8 sp=0x2735e80 pc=0xf2448
Apr 29 14:41:03 motivo go-librespot[3035]: io.ReadAtLeast({0x6cb40c, 0x437c180}, {0x2291b30, 0x1000, 0x7fffffff}, 0x1000)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/io/io.go:332 +0x90 fp=0x2735ed4 sp=0x2735ea8 pc=0xf1b18
Apr 29 14:41:03 motivo go-librespot[3035]: io.ReadFull(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/io/io.go:351
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/vorbis.(*Decoder).readChunk(0x270b400)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/vorbis/decoder.go:172 +0x98 fp=0x2735f18 sp=0x2735ed4 pc=0x4678bc
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/vorbis.(*Decoder).readNextPage(0x270b400)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/vorbis/decoder.go:302 +0x4c fp=0x2735f60 sp=0x2735f18 pc=0x468338
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/vorbis.(*Decoder).Read(0x270b400, {0x2c5a000, 0x8000, 0x8000})
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/vorbis/decoder.go:264 +0x1e4 fp=0x2735f84 sp=0x2735f60 pc=0x468050
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/output.(*output).loop(0x2758330)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:136 +0x98 fp=0x2735fd0 sp=0x2735f84 pc=0x460ad8
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/output.newOutput.func1()
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:66 +0x20 fp=0x2735fec sp=0x2735fd0 pc=0x45feac
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2735fec sp=0x2735fec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by go-librespot/output.newOutput
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:65 +0x1c8
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 1 [select]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x27617e8 sp=0x27617d4 pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.selectgo(0x2761a6c, 0x27619b0, 0x0, 0x0, 0x6, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x2761890 sp=0x27617e8 pc=0x64d80
Apr 29 14:41:03 motivo go-librespot[3035]: main.(*AppPlayer).Run(0x2496480, 0x248e200)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/player.go:361 +0x1e4 fp=0x2761eac sp=0x2761890 pc=0x53c0d0
Apr 29 14:41:03 motivo go-librespot[3035]: main.(*App).withReusableCredentials(0x2558020, {0x5abe70, 0x24aa540})
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:218 +0x660 fp=0x2761f3c sp=0x2761eac pc=0x5382f0
Apr 29 14:41:03 motivo go-librespot[3035]: main.(*App).SpotifyToken(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:159
Apr 29 14:41:03 motivo go-librespot[3035]: main.main()
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:331 +0x524 fp=0x2761fc0 sp=0x2761f3c pc=0x538cf8
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.main()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:250 +0x268 fp=0x2761fec sp=0x2761fc0 pc=0x52288
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2761fec sp=0x2761fec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 2 [force gc (idle), 13 minutes]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f54, 0xa35150, 0x11, 0x14, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x243cfd8 sp=0x243cfc4 pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goparkunlock(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:387
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.forcegchelper()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:305 +0xd4 fp=0x243cfec sp=0x243cfd8 pc=0x525d0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x243cfec sp=0x243cfec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by runtime.init.5
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:293 +0x1c
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 18 [GC sweep wait]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f54, 0xa35750, 0xc, 0x14, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x24387c8 sp=0x24387b4 pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goparkunlock(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:387
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.bgsweep(0x248e000)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgcsweep.go:319 +0x104 fp=0x24387e4 sp=0x24387c8 pc=0x3c528
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gcenable.func1()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:178 +0x28 fp=0x24387ec sp=0x24387e4 pc=0x2cff4
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x24387ec sp=0x24387ec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by runtime.gcenable
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:178 +0x74
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 19 [GC scavenge wait]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f54, 0xa35a30, 0xd, 0x14, 0x2)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x2438fb4 sp=0x2438fa0 pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goparkunlock(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:387
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.(*scavengerState).park(0xa35a30)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgcscavenge.go:400 +0x64 fp=0x2438fc8 sp=0x2438fb4 pc=0x39e1c
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.bgscavenge(0x248e000)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgcscavenge.go:633 +0x64 fp=0x2438fe4 sp=0x2438fc8 pc=0x3a560
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gcenable.func2()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:179 +0x28 fp=0x2438fec sp=0x2438fe4 pc=0x2cfa0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2438fec sp=0x2438fec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by runtime.gcenable
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:179 +0xbc
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 20 [finalizer wait]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642e94, 0xa46af4, 0x10, 0x14, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x243c78c sp=0x243c778 pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.runfinq()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mfinal.go:193 +0xfc fp=0x243c7ec sp=0x243c78c pc=0x2bed0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x243c7ec sp=0x243c7ec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by runtime.createfing
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mfinal.go:163 +0x5c
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 21 [IO wait]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f3c, 0xad2c3f40, 0x2, 0x1b, 0x5)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x24395dc sp=0x24395c8 pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.netpollblock(0xad2c3f34, 0x72, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:527 +0x100 fp=0x24395f4 sp=0x24395dc pc=0x49f2c
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.runtime_pollWait(0xad2c3f34, 0x72)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:306 +0x54 fp=0x2439608 sp=0x24395f4 pc=0x800b4
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*pollDesc).wait(0x24a0e24, 0x72, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x243961c sp=0x2439608 pc=0xf7db0
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*pollDesc).waitRead(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:89
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*FD).Accept(0x24a0e10)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_unix.go:614 +0x2d0 fp=0x243966c sp=0x243961c pc=0xfc8d0
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*netFD).accept(0x24a0e10)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/fd_unix.go:172 +0x20 fp=0x24396cc sp=0x243966c pc=0x281ba8
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*TCPListener).accept(0x24aa530)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/tcpsock_posix.go:148 +0x20 fp=0x24396e4 sp=0x24396cc pc=0x29a540
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*TCPListener).Accept(0x24aa530)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/tcpsock.go:297 +0x30 fp=0x2439700 sp=0x24396e4 pc=0x299504
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*onceCloseListener).Accept(0x2582020)
Apr 29 14:41:03 motivo go-librespot[3035]: :1 +0x34 fp=0x2439718 sp=0x2439700 pc=0x427558
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*Server).Serve(0x258c000, {0x6ccfb0, 0x24aa530})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:3059 +0x344 fp=0x24397b4 sp=0x2439718 pc=0x403550
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.Serve(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:2581
Apr 29 14:41:03 motivo go-librespot[3035]: main.(*ApiServer).serve(0x2495a00)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:438 +0x62c fp=0x24397e4 sp=0x24397b4 pc=0x532118
Apr 29 14:41:03 motivo go-librespot[3035]: main.NewApiServer.func1()
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:237 +0x28 fp=0x24397ec sp=0x24397e4 pc=0x5317d0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x24397ec sp=0x24397ec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by main.NewApiServer
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:237 +0x1dc
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 83 [select]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x259fea0 sp=0x259fe8c pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.selectgo(0x259ffbc, 0x259ff74, 0x0, 0x0, 0x5, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x259ff48 sp=0x259fea0 pc=0x64d80
Apr 29 14:41:03 motivo go-librespot[3035]: nhooyr.io/websocket.(*Conn).timeoutLoop(0x27ae5a0)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:153 +0x110 fp=0x259ffe4 sp=0x259ff48 pc=0x43d0c8
Apr 29 14:41:03 motivo go-librespot[3035]: nhooyr.io/websocket.newConn.func2()
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x28 fp=0x259ffec sp=0x259ffe4 pc=0x43ccbc
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x259ffec sp=0x259ffec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by nhooyr.io/websocket.newConn
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x5b0
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 54 [IO wait, 13 minutes]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f3c, 0xad2c3afc, 0x2, 0x1b, 0x5)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x244a880 sp=0x244a86c pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.netpollblock(0xad2c3af0, 0x72, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:527 +0x100 fp=0x244a898 sp=0x244a880 pc=0x49f2c
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.runtime_pollWait(0xad2c3af0, 0x72)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:306 +0x54 fp=0x244a8ac sp=0x244a898 pc=0x800b4
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*pollDesc).wait(0x27259b4, 0x72, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x244a8c0 sp=0x244a8ac pc=0xf7db0
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*pollDesc).waitRead(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:89
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*FD).Read(0x27259a0, {0x2768000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_unix.go:167 +0x240 fp=0x244a910 sp=0x244a8c0 pc=0xf8fbc
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*netFD).Read(0x27259a0, {0x2768000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/fd_posix.go:55 +0x38 fp=0x244a93c sp=0x244a910 pc=0x27faec
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*conn).Read(0x2698e70, {0x2768000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/net.go:183 +0x48 fp=0x244a96c sp=0x244a93c pc=0x290a70
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*TCPConn).Read(0x2698e70, {0x2768000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: :1 +0x44 fp=0x244a98c sp=0x244a96c pc=0x2a514c
Apr 29 14:41:03 motivo go-librespot[3035]: io.(*multiReader).Read(0x27e03d0, {0x2768000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/io/multi.go:26 +0xac fp=0x244a9c0 sp=0x244a98c pc=0xf2de0
Apr 29 14:41:03 motivo go-librespot[3035]: bufio.(*Reader).fill(0x2726b10)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/bufio/bufio.go:106 +0x10c fp=0x244a9e4 sp=0x244a9c0 pc=0x144f14
Apr 29 14:41:03 motivo go-librespot[3035]: bufio.(*Reader).ReadByte(0x2726b10)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/bufio/bufio.go:265 +0x28 fp=0x244a9f0 sp=0x244a9e4 pc=0x1457c4
Apr 29 14:41:03 motivo go-librespot[3035]: nhooyr.io/websocket.readFrameHeader(0x2726b10, {0x27ae5d0, 0x8, 0x8})
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/frame.go:54 +0x74 fp=0x244aa30 sp=0x244a9f0 pc=0x440024
Apr 29 14:41:03 motivo go-librespot[3035]: nhooyr.io/websocket.(*Conn).readFrameHeader(0x27ae5a0, {0x6cd2ac, 0x24a2020})
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:188 +0xb4 fp=0x244aaf0 sp=0x244aa30 pc=0x442b84
Apr 29 14:41:03 motivo go-librespot[3035]: nhooyr.io/websocket.(*Conn).readLoop(0x27ae5a0, {0x6cd2ac, 0x24a2020})
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:146 +0x3c fp=0x244abb4 sp=0x244aaf0 pc=0x44265c
Apr 29 14:41:03 motivo go-librespot[3035]: nhooyr.io/websocket.(*Conn).reader(0x27ae5a0, {0x6cd2ac, 0x24a2020})
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:315 +0x10c fp=0x244ac40 sp=0x244abb4 pc=0x44389c
Apr 29 14:41:03 motivo go-librespot[3035]: nhooyr.io/websocket.(*Conn).Reader(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:30
Apr 29 14:41:03 motivo go-librespot[3035]: nhooyr.io/websocket.(*Conn).Read(0x27ae5a0, {0x6cd2ac, 0x24a2020})
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:36 +0x2c fp=0x244ac68 sp=0x244ac40 pc=0x441f28
Apr 29 14:41:03 motivo go-librespot[3035]: main.(*ApiServer).serve.func13({0x6cd0e4, 0x26bab40}, 0x26b8380)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:418 +0x24c fp=0x244acc4 sp=0x244ac68 pc=0x5325d0
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.HandlerFunc.ServeHTTP(0x2588058, {0x6cd0e4, 0x26bab40}, 0x26b8380)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:2122 +0x34 fp=0x244acd4 sp=0x244acc4 pc=0x40026c
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*ServeMux).ServeHTTP(0x2580000, {0x6cd0e4, 0x26bab40}, 0x26b8380)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:2500 +0x164 fp=0x244ad00 sp=0x244acd4 pc=0x401ab4
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.serverHandler.ServeHTTP({0x258c000}, {0x6cd0e4, 0x26bab40}, 0x26b8380)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:2936 +0x304 fp=0x244ad58 sp=0x244ad00 pc=0x402fc0
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*conn).serve(0x26ab560, {0x6cd2ec, 0x2594000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:1995 +0x654 fp=0x244afdc sp=0x244ad58 pc=0x3feb34
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*Server).Serve.func3()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:3089 +0x38 fp=0x244afec sp=0x244afdc pc=0x4039f4
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x244afec sp=0x244afec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by net/http.(*Server).Serve
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:3089 +0x4e0
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 35 [GC worker (idle)]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642ea0, 0x2721cc8, 0x1a, 0x14, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x2439f90 sp=0x2439f7c pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gcBgMarkWorker()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1275 +0x100 fp=0x2439fec sp=0x2439f90 pc=0x2fbb8
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2439fec sp=0x2439fec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by runtime.gcBgMarkStartWorkers
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1199 +0x20
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 27 [GC worker (idle)]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642ea0, 0x24ba690, 0x1a, 0x14, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x243a790 sp=0x243a77c pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gcBgMarkWorker()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1275 +0x100 fp=0x243a7ec sp=0x243a790 pc=0x2fbb8
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x243a7ec sp=0x243a7ec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by runtime.gcBgMarkStartWorkers
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1199 +0x20
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 36 [GC worker (idle)]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642ea0, 0x2721ce0, 0x1a, 0x14, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x259e790 sp=0x259e77c pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gcBgMarkWorker()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1275 +0x100 fp=0x259e7ec sp=0x259e790 pc=0x2fbb8
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x259e7ec sp=0x259e7ec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by runtime.gcBgMarkStartWorkers
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1199 +0x20
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 28 [GC worker (idle)]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642ea0, 0x24ba6a8, 0x1a, 0x14, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x243af90 sp=0x243af7c pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gcBgMarkWorker()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1275 +0x100 fp=0x243afec sp=0x243af90 pc=0x2fbb8
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x243afec sp=0x243afec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by runtime.gcBgMarkStartWorkers
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1199 +0x20
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 69 [select]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x243dea0 sp=0x243de8c pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.selectgo(0x243dfbc, 0x243df74, 0x0, 0x0, 0x5, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x243df48 sp=0x243dea0 pc=0x64d80
Apr 29 14:41:03 motivo go-librespot[3035]: nhooyr.io/websocket.(*Conn).timeoutLoop(0x26166c0)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:153 +0x110 fp=0x243dfe4 sp=0x243df48 pc=0x43d0c8
Apr 29 14:41:03 motivo go-librespot[3035]: nhooyr.io/websocket.newConn.func2()
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x28 fp=0x243dfec sp=0x243dfe4 pc=0x43ccbc
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x243dfec sp=0x243dfec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by nhooyr.io/websocket.newConn
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x5b0
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 10 [select, 1 minutes]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x259dea0 sp=0x259de8c pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.selectgo(0x259dfac, 0x259df94, 0x0, 0x0, 0x2, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x259df48 sp=0x259dea0 pc=0x64d80
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/ap.(*Accesspoint).pongAckTicker(0x25bc1b0)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:301 +0x8c fp=0x259dfe4 sp=0x259df48 pc=0x455290
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/ap.NewAccesspoint.func1()
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:66 +0x28 fp=0x259dfec sp=0x259dfe4 pc=0x453674
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x259dfec sp=0x259dfec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by go-librespot/ap.NewAccesspoint
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:66 +0x190
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 70 [select]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x29b6e7c sp=0x29b6e68 pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.selectgo(0x29b6fac, 0x29b6f78, 0x0, 0x0, 0x2, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x29b6f24 sp=0x29b6e7c pc=0x64d80
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/dealer.(*Dealer).pingTicker(0x24a5170)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:105 +0x8c fp=0x29b6fe4 sp=0x29b6f24 pc=0x4783f4
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/dealer.NewDealer.func1()
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:57 +0x28 fp=0x29b6fec sp=0x29b6fe4 pc=0x477d90
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x29b6fec sp=0x29b6fec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by go-librespot/dealer.NewDealer
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:57 +0x174
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 71 [select]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x259f694 sp=0x259f680 pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.selectgo(0x259f7b0, 0x259f784, 0x0, 0x0, 0x2, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x259f73c sp=0x259f694 pc=0x64d80
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/player.(*Player).manageLoop(0x2654740)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/player/player.go:102 +0xd4 fp=0x259f7e4 sp=0x259f73c pc=0x46922c
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/player.NewPlayer.func2()
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/player/player.go:86 +0x28 fp=0x259f7ec sp=0x259f7e4 pc=0x469094
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x259f7ec sp=0x259f7ec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by go-librespot/player.NewPlayer
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/player/player.go:86 +0x1bc
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 72 [IO wait]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f3c, 0xad2c3d6c, 0x2, 0x1b, 0x5)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x2479d88 sp=0x2479d74 pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.netpollblock(0xad2c3d60, 0x72, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:527 +0x100 fp=0x2479da0 sp=0x2479d88 pc=0x49f2c
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.runtime_pollWait(0xad2c3d60, 0x72)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:306 +0x54 fp=0x2479db4 sp=0x2479da0 pc=0x800b4
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*pollDesc).wait(0x2618064, 0x72, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2479dc8 sp=0x2479db4 pc=0xf7db0
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*pollDesc).waitRead(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:89
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*FD).Read(0x2618050, {0x26f423c, 0x3, 0x3})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_unix.go:167 +0x240 fp=0x2479e18 sp=0x2479dc8 pc=0xf8fbc
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*netFD).Read(0x2618050, {0x26f423c, 0x3, 0x3})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/fd_posix.go:55 +0x38 fp=0x2479e44 sp=0x2479e18 pc=0x27faec
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*conn).Read(0x25886a8, {0x26f423c, 0x3, 0x3})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/net.go:183 +0x48 fp=0x2479e74 sp=0x2479e44 pc=0x290a70
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*TCPConn).Read(0x25886a8, {0x26f423c, 0x3, 0x3})
Apr 29 14:41:03 motivo go-librespot[3035]: :1 +0x44 fp=0x2479e94 sp=0x2479e74 pc=0x2a514c
Apr 29 14:41:03 motivo go-librespot[3035]: io.ReadAtLeast({0x6cb4d4, 0x25886a8}, {0x26f423c, 0x3, 0x3}, 0x3)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/io/io.go:332 +0x90 fp=0x2479ec0 sp=0x2479e94 pc=0xf1b18
Apr 29 14:41:03 motivo go-librespot[3035]: io.ReadFull(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/io/io.go:351
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/ap.(*shannonConn).receivePacket(0x2689140)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/ap/shannon.go:80 +0x124 fp=0x2479f20 sp=0x2479ec0 pc=0x457ddc
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/ap.(*Accesspoint).recvLoop(0x25bc1b0)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:239 +0x58 fp=0x2479fe4 sp=0x2479f20 pc=0x454c1c
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/ap.(*Accesspoint).startReceiving.func1.1()
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:228 +0x28 fp=0x2479fec sp=0x2479fe4 pc=0x454b98
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2479fec sp=0x2479fec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by go-librespot/ap.(*Accesspoint).startReceiving.func1
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:228 +0x60
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 73 [IO wait]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f3c, 0xad2c3c34, 0x2, 0x1b, 0x5)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x276390c sp=0x27638f8 pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.netpollblock(0xad2c3c28, 0x72, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:527 +0x100 fp=0x2763924 sp=0x276390c pc=0x49f2c
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.runtime_pollWait(0xad2c3c28, 0x72)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:306 +0x54 fp=0x2763938 sp=0x2763924 pc=0x800b4
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*pollDesc).wait(0x256c154, 0x72, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x276394c sp=0x2763938 pc=0xf7db0
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*pollDesc).waitRead(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:89
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*FD).Read(0x256c140, {0x2836000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_unix.go:167 +0x240 fp=0x276399c sp=0x276394c pc=0xf8fbc
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*netFD).Read(0x256c140, {0x2836000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/fd_posix.go:55 +0x38 fp=0x27639c8 sp=0x276399c pc=0x27faec
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*conn).Read(0x2589430, {0x2836000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/net.go:183 +0x48 fp=0x27639f8 sp=0x27639c8 pc=0x290a70
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*TCPConn).Read(0x2589430, {0x2836000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: :1 +0x44 fp=0x2763a18 sp=0x27639f8 pc=0x2a514c
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*atLeastReader).Read(0x27e13d0, {0x2836000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:788 +0x7c fp=0x2763a48 sp=0x2763a18 pc=0x35d4b0
Apr 29 14:41:03 motivo go-librespot[3035]: bytes.(*Buffer).ReadFrom(0x24bdf78, {0x6ca124, 0x27e13d0})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/bytes/buffer.go:202 +0xa4 fp=0x2763a88 sp=0x2763a48 pc=0x124eb4
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*Conn).readFromUntil(0x24bde00, {0x6cb4d4, 0x2589430}, 0x5)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:810 +0xd4 fp=0x2763ab0 sp=0x2763a88 pc=0x35d720
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*Conn).readRecordOrCCS(0x24bde00, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:617 +0x11c fp=0x2763c2c sp=0x2763ab0 pc=0x35af50
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*Conn).readRecord(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:583
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*Conn).Read(0x24bde00, {0x2847000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:1316 +0x168 fp=0x2763c5c sp=0x2763c2c pc=0x3606f8
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*readWriteCloserBody).Read(0x2673420, {0x2847000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/transport.go:2395 +0xf4 fp=0x2763c7c sp=0x2763c5c pc=0x419be0
Apr 29 14:41:03 motivo go-librespot[3035]: bufio.(*Reader).fill(0x2643cb0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/bufio/bufio.go:106 +0x10c fp=0x2763ca0 sp=0x2763c7c pc=0x144f14
Apr 29 14:41:03 motivo go-librespot[3035]: bufio.(*Reader).ReadByte(0x2643cb0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/bufio/bufio.go:265 +0x28 fp=0x2763cac sp=0x2763ca0 pc=0x1457c4
Apr 29 14:41:03 motivo go-librespot[3035]: nhooyr.io/websocket.readFrameHeader(0x2643cb0, {0x26166f0, 0x8, 0x8})
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/frame.go:54 +0x74 fp=0x2763cec sp=0x2763cac pc=0x440024
Apr 29 14:41:03 motivo go-librespot[3035]: nhooyr.io/websocket.(*Conn).readFrameHeader(0x26166c0, {0x6cd2ac, 0x24a2020})
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:188 +0xb4 fp=0x2763dac sp=0x2763cec pc=0x442b84
Apr 29 14:41:03 motivo go-librespot[3035]: nhooyr.io/websocket.(*Conn).readLoop(0x26166c0, {0x6cd2ac, 0x24a2020})
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:146 +0x3c fp=0x2763e70 sp=0x2763dac pc=0x44265c
Apr 29 14:41:03 motivo go-librespot[3035]: nhooyr.io/websocket.(*Conn).reader(0x26166c0, {0x6cd2ac, 0x24a2020})
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:315 +0x10c fp=0x2763efc sp=0x2763e70 pc=0x44389c
Apr 29 14:41:03 motivo go-librespot[3035]: nhooyr.io/websocket.(*Conn).Reader(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:30
Apr 29 14:41:03 motivo go-librespot[3035]: nhooyr.io/websocket.(*Conn).Read(0x26166c0, {0x6cd2ac, 0x24a2020})
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:36 +0x2c fp=0x2763f24 sp=0x2763efc pc=0x441f28
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/dealer.(*Dealer).recvLoop(0x24a5170)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:151 +0x5c fp=0x2763fe4 sp=0x2763f24 pc=0x478850
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/dealer.(*Dealer).startReceiving.func1.1()
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:97 +0x28 fp=0x2763fec sp=0x2763fe4 pc=0x47833c
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2763fec sp=0x2763fec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by go-librespot/dealer.(*Dealer).startReceiving.func1
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:97 +0x60
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 101 [select]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x2476c9c sp=0x2476c88 pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.selectgo(0x2476e1c, 0x2476d94, 0x0, 0x0, 0x3, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x2476d44 sp=0x2476c9c pc=0x64d80
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/audio.(*KeyProvider).recvLoop(0x25f0fd8)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/audio/provider.go:52 +0x118 fp=0x2476fe4 sp=0x2476d44 pc=0x45dd70
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/audio.(*KeyProvider).startReceiving.func1.1()
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/audio/provider.go:42 +0x28 fp=0x2476fec sp=0x2476fe4 pc=0x45dc2c
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2476fec sp=0x2476fec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by go-librespot/audio.(*KeyProvider).startReceiving.func1
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/audio/provider.go:42 +0x60
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 194626 [IO wait]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f3c, 0xad2c34e4, 0x2, 0x1b, 0x5)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x2739ac8 sp=0x2739ab4 pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.netpollblock(0xad2c34d8, 0x72, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:527 +0x100 fp=0x2739ae0 sp=0x2739ac8 pc=0x49f2c
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.runtime_pollWait(0xad2c34d8, 0x72)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:306 +0x54 fp=0x2739af4 sp=0x2739ae0 pc=0x800b4
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*pollDesc).wait(0x29a8514, 0x72, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2739b08 sp=0x2739af4 pc=0xf7db0
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*pollDesc).waitRead(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:89
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*FD).Read(0x29a8500, {0x4578000, 0xa000, 0xa000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_unix.go:167 +0x240 fp=0x2739b58 sp=0x2739b08 pc=0xf8fbc
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*netFD).Read(0x29a8500, {0x4578000, 0xa000, 0xa000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/fd_posix.go:55 +0x38 fp=0x2739b84 sp=0x2739b58 pc=0x27faec
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*conn).Read(0x268de48, {0x4578000, 0xa000, 0xa000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/net.go:183 +0x48 fp=0x2739bb4 sp=0x2739b84 pc=0x290a70
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*TCPConn).Read(0x268de48, {0x4578000, 0xa000, 0xa000})
Apr 29 14:41:03 motivo go-librespot[3035]: :1 +0x44 fp=0x2739bd4 sp=0x2739bb4 pc=0x2a514c
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*atLeastReader).Read(0x27e1090, {0x4578000, 0xa000, 0xa000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:788 +0x7c fp=0x2739c04 sp=0x2739bd4 pc=0x35d4b0
Apr 29 14:41:03 motivo go-librespot[3035]: bytes.(*Buffer).ReadFrom(0x42fa178, {0x6ca124, 0x27e1090})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/bytes/buffer.go:202 +0xa4 fp=0x2739c44 sp=0x2739c04 pc=0x124eb4
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*Conn).readFromUntil(0x42fa000, {0x6cb4d4, 0x268de48}, 0x5)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:810 +0xd4 fp=0x2739c6c sp=0x2739c44 pc=0x35d720
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*Conn).readRecordOrCCS(0x42fa000, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:617 +0x11c fp=0x2739de8 sp=0x2739c6c pc=0x35af50
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*Conn).readRecord(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:583
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*Conn).Read(0x42fa000, {0x3dfd000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:1316 +0x168 fp=0x2739e18 sp=0x2739de8 pc=0x3606f8
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*persistConn).Read(0x24c4500, {0x3dfd000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/transport.go:1943 +0x16c fp=0x2739e4c sp=0x2739e18 pc=0x417454
Apr 29 14:41:03 motivo go-librespot[3035]: bufio.(*Reader).fill(0x2600f30)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/bufio/bufio.go:106 +0x10c fp=0x2739e70 sp=0x2739e4c pc=0x144f14
Apr 29 14:41:03 motivo go-librespot[3035]: bufio.(*Reader).Peek(0x2600f30, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/bufio/bufio.go:144 +0x68 fp=0x2739e7c sp=0x2739e70 pc=0x145094
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*persistConn).readLoop(0x24c4500)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/transport.go:2107 +0x190 fp=0x2739fe4 sp=0x2739e7c pc=0x417ff0
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*Transport).dialConn.func5()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/transport.go:1765 +0x28 fp=0x2739fec sp=0x2739fe4 pc=0x41691c
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2739fec sp=0x2739fec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by net/http.(*Transport).dialConn
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/transport.go:1765 +0x1410
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 97367 [sync.Cond.Wait, 6 minutes]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f54, 0x27973b0, 0x14, 0x1a, 0x3)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x29a6f38 sp=0x29a6f24 pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goparkunlock(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:387
Apr 29 14:41:03 motivo go-librespot[3035]: sync.runtime_notifyListWait(0x27973a8, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/sema.go:527 +0x1cc fp=0x29a6f60 sp=0x29a6f38 pc=0x81e00
Apr 29 14:41:03 motivo go-librespot[3035]: sync.(*Cond).Wait(0x27973a0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/sync/cond.go:70 +0xbc fp=0x29a6f84 sp=0x29a6f60 pc=0x8c820
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/output.(*output).loop(0x3b7ac00)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:160 +0x328 fp=0x29a6fd0 sp=0x29a6f84 pc=0x460d68
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/output.newOutput.func1()
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:66 +0x20 fp=0x29a6fec sp=0x29a6fd0 pc=0x45feac
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x29a6fec sp=0x29a6fec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by go-librespot/output.newOutput
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:65 +0x1c8
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 194573 [sync.Cond.Wait]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f54, 0x279d870, 0x14, 0x1a, 0x3)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x28a4f38 sp=0x28a4f24 pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goparkunlock(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:387
Apr 29 14:41:03 motivo go-librespot[3035]: sync.runtime_notifyListWait(0x279d868, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/sema.go:527 +0x1cc fp=0x28a4f60 sp=0x28a4f38 pc=0x81e00
Apr 29 14:41:03 motivo go-librespot[3035]: sync.(*Cond).Wait(0x279d860)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/sync/cond.go:70 +0xbc fp=0x28a4f84 sp=0x28a4f60 pc=0x8c820
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/output.(*output).loop(0x48a8c90)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:160 +0x328 fp=0x28a4fd0 sp=0x28a4f84 pc=0x460d68
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/output.newOutput.func1()
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:66 +0x20 fp=0x28a4fec sp=0x28a4fd0 pc=0x45feac
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x28a4fec sp=0x28a4fec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by go-librespot/output.newOutput
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:65 +0x1c8
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 97439 [select]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x244fec4 sp=0x244feb0 pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.selectgo(0x244ffd0, 0x244ff9c, 0x0, 0x0, 0x2, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x244ff6c sp=0x244fec4 pc=0x64d80
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*persistConn).writeLoop(0x26bb040)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/transport.go:2410 +0xcc fp=0x244ffe4 sp=0x244ff6c pc=0x419cf8
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*Transport).dialConn.func6()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/transport.go:1766 +0x28 fp=0x244ffec sp=0x244ffe4 pc=0x4168c8
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x244ffec sp=0x244ffec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by net/http.(*Transport).dialConn
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/transport.go:1766 +0x1460
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 8649 [sync.Cond.Wait, 12 minutes]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f54, 0x279c250, 0x14, 0x1a, 0x3)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x2913738 sp=0x2913724 pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goparkunlock(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:387
Apr 29 14:41:03 motivo go-librespot[3035]: sync.runtime_notifyListWait(0x279c248, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/sema.go:527 +0x1cc fp=0x2913760 sp=0x2913738 pc=0x81e00
Apr 29 14:41:03 motivo go-librespot[3035]: sync.(*Cond).Wait(0x279c240)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/sync/cond.go:70 +0xbc fp=0x2913784 sp=0x2913760 pc=0x8c820
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/output.(*output).loop(0x2496510)
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:160 +0x328 fp=0x29137d0 sp=0x2913784 pc=0x460d68
Apr 29 14:41:03 motivo go-librespot[3035]: go-librespot/output.newOutput.func1()
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:66 +0x20 fp=0x29137ec sp=0x29137d0 pc=0x45feac
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x29137ec sp=0x29137ec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by go-librespot/output.newOutput
Apr 29 14:41:03 motivo go-librespot[3035]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:65 +0x1c8
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 194627 [select]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f84, 0x0, 0x9, 0x18, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x440d6c4 sp=0x440d6b0 pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.selectgo(0x440d7d0, 0x440d79c, 0x0, 0x0, 0x2, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x440d76c sp=0x440d6c4 pc=0x64d80
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*persistConn).writeLoop(0x24c4500)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/transport.go:2410 +0xcc fp=0x440d7e4 sp=0x440d76c pc=0x419cf8
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*Transport).dialConn.func6()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/transport.go:1766 +0x28 fp=0x440d7ec sp=0x440d7e4 pc=0x4168c8
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x440d7ec sp=0x440d7ec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by net/http.(*Transport).dialConn
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/transport.go:1766 +0x1460
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 194579 [IO wait]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f3c, 0xad2c3580, 0x2, 0x1b, 0x5)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x244ba7c sp=0x244ba68 pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.netpollblock(0xad2c3574, 0x72, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:527 +0x100 fp=0x244ba94 sp=0x244ba7c pc=0x49f2c
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.runtime_pollWait(0xad2c3574, 0x72)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:306 +0x54 fp=0x244baa8 sp=0x244ba94 pc=0x800b4
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*pollDesc).wait(0x28912d4, 0x72, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x244babc sp=0x244baa8 pc=0xf7db0
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*pollDesc).waitRead(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:89
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*FD).Read(0x28912c0, {0x284b000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_unix.go:167 +0x240 fp=0x244bb0c sp=0x244babc pc=0xf8fbc
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*netFD).Read(0x28912c0, {0x284b000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/fd_posix.go:55 +0x38 fp=0x244bb38 sp=0x244bb0c pc=0x27faec
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*conn).Read(0x44b49b8, {0x284b000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/net.go:183 +0x48 fp=0x244bb68 sp=0x244bb38 pc=0x290a70
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*TCPConn).Read(0x44b49b8, {0x284b000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: :1 +0x44 fp=0x244bb88 sp=0x244bb68 pc=0x2a514c
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*atLeastReader).Read(0x240e330, {0x284b000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:788 +0x7c fp=0x244bbb8 sp=0x244bb88 pc=0x35d4b0
Apr 29 14:41:03 motivo go-librespot[3035]: bytes.(*Buffer).ReadFrom(0x24bc178, {0x6ca124, 0x240e330})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/bytes/buffer.go:202 +0xa4 fp=0x244bbf8 sp=0x244bbb8 pc=0x124eb4
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*Conn).readFromUntil(0x24bc000, {0x6cb4d4, 0x44b49b8}, 0x5)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:810 +0xd4 fp=0x244bc20 sp=0x244bbf8 pc=0x35d720
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*Conn).readRecordOrCCS(0x24bc000, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:617 +0x11c fp=0x244bd9c sp=0x244bc20 pc=0x35af50
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*Conn).readRecord(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:583
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*Conn).Read(0x24bc000, {0x2629000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:1316 +0x168 fp=0x244bdcc sp=0x244bd9c pc=0x3606f8
Apr 29 14:41:03 motivo go-librespot[3035]: bufio.(*Reader).Read(0x4374cc0, {0x24d02a4, 0x9, 0x9})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/bufio/bufio.go:237 +0x228 fp=0x244bdf0 sp=0x244bdcc pc=0x1455b4
Apr 29 14:41:03 motivo go-librespot[3035]: io.ReadAtLeast({0x6ca00c, 0x4374cc0}, {0x24d02a4, 0x9, 0x9}, 0x9)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/io/io.go:332 +0x90 fp=0x244be1c sp=0x244bdf0 pc=0xf1b18
Apr 29 14:41:03 motivo go-librespot[3035]: io.ReadFull(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/io/io.go:351
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.http2readFrameHeader({0x24d02a4, 0x9, 0x9}, {0x6ca00c, 0x4374cc0})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/h2_bundle.go:1567 +0x54 fp=0x244be44 sp=0x244be1c pc=0x3c1c38
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*http2Framer).ReadFrame(0x24d0280)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/h2_bundle.go:1831 +0x94 fp=0x244bec8 sp=0x244be44 pc=0x3c2434
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*http2clientConnReadLoop).run(0x244bfd4)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/h2_bundle.go:9187 +0x150 fp=0x244bfa4 sp=0x244bec8 pc=0x3e621c
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*http2ClientConn).readLoop(0x25fee10)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/h2_bundle.go:9082 +0x68 fp=0x244bfe4 sp=0x244bfa4 pc=0x3e570c
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*http2Transport).newClientConn.func1()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/h2_bundle.go:7779 +0x28 fp=0x244bfec sp=0x244bfe4 pc=0x3de8b4
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x244bfec sp=0x244bfec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by net/http.(*http2Transport).newClientConn
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/h2_bundle.go:7779 +0xc24
Apr 29 14:41:03 motivo go-librespot[3035]: goroutine 97438 [IO wait]:
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.gopark(0x642f3c, 0xad2c3b98, 0x2, 0x1b, 0x5)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x2737ac8 sp=0x2737ab4 pc=0x527b0
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.netpollblock(0xad2c3b8c, 0x72, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:527 +0x100 fp=0x2737ae0 sp=0x2737ac8 pc=0x49f2c
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.runtime_pollWait(0xad2c3b8c, 0x72)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:306 +0x54 fp=0x2737af4 sp=0x2737ae0 pc=0x800b4
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*pollDesc).wait(0x2890294, 0x72, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2737b08 sp=0x2737af4 pc=0xf7db0
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*pollDesc).waitRead(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:89
Apr 29 14:41:03 motivo go-librespot[3035]: internal/poll.(*FD).Read(0x2890280, {0x43b6000, 0xa000, 0xa000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_unix.go:167 +0x240 fp=0x2737b58 sp=0x2737b08 pc=0xf8fbc
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*netFD).Read(0x2890280, {0x43b6000, 0xa000, 0xa000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/fd_posix.go:55 +0x38 fp=0x2737b84 sp=0x2737b58 pc=0x27faec
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*conn).Read(0x2983fd8, {0x43b6000, 0xa000, 0xa000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/net.go:183 +0x48 fp=0x2737bb4 sp=0x2737b84 pc=0x290a70
Apr 29 14:41:03 motivo go-librespot[3035]: net.(*TCPConn).Read(0x2983fd8, {0x43b6000, 0xa000, 0xa000})
Apr 29 14:41:03 motivo go-librespot[3035]: :1 +0x44 fp=0x2737bd4 sp=0x2737bb4 pc=0x2a514c
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*atLeastReader).Read(0x26be750, {0x43b6000, 0xa000, 0xa000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:788 +0x7c fp=0x2737c04 sp=0x2737bd4 pc=0x35d4b0
Apr 29 14:41:03 motivo go-librespot[3035]: bytes.(*Buffer).ReadFrom(0x24bc378, {0x6ca124, 0x26be750})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/bytes/buffer.go:202 +0xa4 fp=0x2737c44 sp=0x2737c04 pc=0x124eb4
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*Conn).readFromUntil(0x24bc200, {0x6cb4d4, 0x2983fd8}, 0x5)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:810 +0xd4 fp=0x2737c6c sp=0x2737c44 pc=0x35d720
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*Conn).readRecordOrCCS(0x24bc200, 0x0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:617 +0x11c fp=0x2737de8 sp=0x2737c6c pc=0x35af50
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*Conn).readRecord(...)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:583
Apr 29 14:41:03 motivo go-librespot[3035]: crypto/tls.(*Conn).Read(0x24bc200, {0x4414000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/crypto/tls/conn.go:1316 +0x168 fp=0x2737e18 sp=0x2737de8 pc=0x3606f8
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*persistConn).Read(0x26bb040, {0x4414000, 0x1000, 0x1000})
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/transport.go:1943 +0x16c fp=0x2737e4c sp=0x2737e18 pc=0x417454
Apr 29 14:41:03 motivo go-librespot[3035]: bufio.(*Reader).fill(0x43c0cf0)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/bufio/bufio.go:106 +0x10c fp=0x2737e70 sp=0x2737e4c pc=0x144f14
Apr 29 14:41:03 motivo go-librespot[3035]: bufio.(*Reader).Peek(0x43c0cf0, 0x1)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/bufio/bufio.go:144 +0x68 fp=0x2737e7c sp=0x2737e70 pc=0x145094
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*persistConn).readLoop(0x26bb040)
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/transport.go:2107 +0x190 fp=0x2737fe4 sp=0x2737e7c pc=0x417ff0
Apr 29 14:41:03 motivo go-librespot[3035]: net/http.(*Transport).dialConn.func5()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/transport.go:1765 +0x28 fp=0x2737fec sp=0x2737fe4 pc=0x41691c
Apr 29 14:41:03 motivo go-librespot[3035]: runtime.goexit()
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2737fec sp=0x2737fec pc=0x84730
Apr 29 14:41:03 motivo go-librespot[3035]: created by net/http.(*Transport).dialConn
Apr 29 14:41:03 motivo go-librespot[3035]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/transport.go:1765 +0x1410
Apr 29 14:41:03 motivo go-librespot[3035]: Aborted
Apr 29 14:41:03 motivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=134/n/a
Apr 29 14:41:03 motivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 29 14:41:03 motivo volumio[929]: info: Connection to go-librespot Websocket closed
Apr 29 14:41:03 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri
Apr 29 14:41:03 motivo volumio[929]: info: In handleBrowseUri, curUri=spotify:album:6WfKfS1LF0VNBjYagEpDAZ
Apr 29 14:41:04 motivo volumio[929]: 0+0 records in
Apr 29 14:41:04 motivo volumio[929]: 0+0 records out
Apr 29 14:41:04 motivo volumio[929]: 0 bytes copied, 0.000236051 s, 0.0 kB/s
Apr 29 14:41:04 motivo volumio[929]: info: camilladsp spawned new process with pid 3799, instance 1, run: true
Apr 29 14:41:04 motivo volumio[929]: info: Preload queue cleared
Apr 29 14:41:04 motivo volumio[929]: info: Preloading song: spotify:track:2yr2PT2hTA44W9cfMwiOwR
Apr 29 14:41:04 motivo volumio[929]: info: Preloading song: spotify:track:3Ny6tr4j7O72jYPynuWZTb
Apr 29 14:41:04 motivo volumio[929]: info: Preloading song: spotify:track:5oyNxZH1dmmkTLMp8V8asz
Apr 29 14:41:04 motivo volumio[929]: info: Preloading song: spotify:track:5kZ0YQVPwJOyntgxiFuxhy
Apr 29 14:41:04 motivo volumio[929]: info: Preloading song: spotify:track:0CY3VEeGMjFNRBNHfcSwE8
Apr 29 14:41:04 motivo volumio[929]: info: Preloading song: spotify:track:7snvFzDeMiQXCQAkYhXilp
Apr 29 14:41:04 motivo volumio[929]: info: Preloading song: spotify:track:0lwy8DfDNHBaDBJXlazoki
Apr 29 14:41:04 motivo volumio[929]: info: Preloading song: spotify:track:73DkCcRcvoefKPTMKmT5W9
Apr 29 14:41:04 motivo volumio[929]: info: Preloading song: spotify:track:0emF6zsR7GaQFWN3Aw3RKa
Apr 29 14:41:04 motivo volumio[929]: info: Preloading song: spotify:track:6nR6cg8epsnG3kczC8PV0P
Apr 29 14:41:04 motivo volumio[929]: info: Preloading song: spotify:track:5g2HNGrMyjTK8mwYs5PswH
Apr 29 14:41:04 motivo volumio[929]: info: Preloading song: spotify:track:3rZpkC90y5YHN2q615MudW
Apr 29 14:41:04 motivo volumio[929]: info: Exploding uri spotify:track:2yr2PT2hTA44W9cfMwiOwR in service spop
Apr 29 14:41:04 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:2yr2PT2hTA44W9cfMwiOwR
Apr 29 14:41:04 motivo volumio[929]: info: Exploding uri spotify:track:3Ny6tr4j7O72jYPynuWZTb in service spop
Apr 29 14:41:04 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:3Ny6tr4j7O72jYPynuWZTb
Apr 29 14:41:04 motivo volumio[929]: info: Exploding uri spotify:track:5oyNxZH1dmmkTLMp8V8asz in service spop
Apr 29 14:41:04 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:5oyNxZH1dmmkTLMp8V8asz
Apr 29 14:41:04 motivo volumio[929]: info: Exploding uri spotify:track:5kZ0YQVPwJOyntgxiFuxhy in service spop
Apr 29 14:41:04 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:5kZ0YQVPwJOyntgxiFuxhy
Apr 29 14:41:05 motivo volumio[929]: info: Exploding uri spotify:track:0CY3VEeGMjFNRBNHfcSwE8 in service spop
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:0CY3VEeGMjFNRBNHfcSwE8
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2yr2PT2hTA44W9cfMwiOwR","service":"spop","name":"In assenza di te","artist":"Daniela Ligorio","album":"Una canzone per te, vol. 1","type":"song","duration":218,"albumart":"https://i.scdn.co/image/ab67616d0000b2732f6ae08ea28c92548c9082f0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:05 motivo volumio[929]: info: Exploding uri spotify:track:7snvFzDeMiQXCQAkYhXilp in service spop
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:7snvFzDeMiQXCQAkYhXilp
Apr 29 14:41:05 motivo volumio[929]: info: Executing endpoint getSimilarAlbums
Apr 29 14:41:05 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums
Apr 29 14:41:05 motivo volumio[929]: info: Exploding uri spotify:track:0lwy8DfDNHBaDBJXlazoki in service spop
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:0lwy8DfDNHBaDBJXlazoki
Apr 29 14:41:05 motivo volumio[929]: info: Executing endpoint getSimilarAlbums
Apr 29 14:41:05 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums
Apr 29 14:41:05 motivo volumio[929]: info: Exploding uri spotify:track:73DkCcRcvoefKPTMKmT5W9 in service spop
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:73DkCcRcvoefKPTMKmT5W9
Apr 29 14:41:05 motivo volumio[929]: info: Executing endpoint metavolumio
Apr 29 14:41:05 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 29 14:41:05 motivo volumio[929]: info: Executing endpoint metavolumio
Apr 29 14:41:05 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 29 14:41:05 motivo volumio[929]: info: Executing endpoint metavolumio
Apr 29 14:41:05 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 29 14:41:05 motivo volumio[929]: info: Executing endpoint metavolumio
Apr 29 14:41:05 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 29 14:41:05 motivo volumio[929]: info: Exploding uri spotify:track:0emF6zsR7GaQFWN3Aw3RKa in service spop
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:0emF6zsR7GaQFWN3Aw3RKa
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3Ny6tr4j7O72jYPynuWZTb","service":"spop","name":"Treno","artist":"Daniela Ligorio","album":"Una canzone per te, vol. 1","type":"song","duration":250,"albumart":"https://i.scdn.co/image/ab67616d0000b2732f6ae08ea28c92548c9082f0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:05 motivo volumio[929]: info: Exploding uri spotify:track:6nR6cg8epsnG3kczC8PV0P in service spop
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:6nR6cg8epsnG3kczC8PV0P
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5oyNxZH1dmmkTLMp8V8asz","service":"spop","name":"Sei nell'anima","artist":"Daniela Ligorio","album":"Una canzone per te, vol. 1","type":"song","duration":265,"albumart":"https://i.scdn.co/image/ab67616d0000b2732f6ae08ea28c92548c9082f0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:05 motivo volumio[929]: info: Exploding uri spotify:track:5g2HNGrMyjTK8mwYs5PswH in service spop
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:5g2HNGrMyjTK8mwYs5PswH
Apr 29 14:41:05 motivo volumio[929]: info: Exploding uri spotify:track:3rZpkC90y5YHN2q615MudW in service spop
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:3rZpkC90y5YHN2q615MudW
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0CY3VEeGMjFNRBNHfcSwE8","service":"spop","name":"Luna messicana","artist":"Daniela Ligorio","album":"Una canzone per te, vol. 1","type":"song","duration":186,"albumart":"https://i.scdn.co/image/ab67616d0000b2732f6ae08ea28c92548c9082f0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5kZ0YQVPwJOyntgxiFuxhy","service":"spop","name":"Se perdo te","artist":"Daniela Ligorio","album":"Una canzone per te, vol. 1","type":"song","duration":229,"albumart":"https://i.scdn.co/image/ab67616d0000b2732f6ae08ea28c92548c9082f0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0lwy8DfDNHBaDBJXlazoki","service":"spop","name":"Essere una donna","artist":"Daniela Ligorio","album":"Una canzone per te, vol. 1","type":"song","duration":240,"albumart":"https://i.scdn.co/image/ab67616d0000b2732f6ae08ea28c92548c9082f0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7snvFzDeMiQXCQAkYhXilp","service":"spop","name":"Lui","artist":"Daniela Ligorio","album":"Una canzone per te, vol. 1","type":"song","duration":296,"albumart":"https://i.scdn.co/image/ab67616d0000b2732f6ae08ea28c92548c9082f0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:73DkCcRcvoefKPTMKmT5W9","service":"spop","name":"Angeli nel blu","artist":"Daniela Ligorio","album":"Una canzone per te, vol. 1","type":"song","duration":262,"albumart":"https://i.scdn.co/image/ab67616d0000b2732f6ae08ea28c92548c9082f0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0emF6zsR7GaQFWN3Aw3RKa","service":"spop","name":"Primavera","artist":"Daniela Ligorio","album":"Una canzone per te, vol. 1","type":"song","duration":242,"albumart":"https://i.scdn.co/image/ab67616d0000b2732f6ae08ea28c92548c9082f0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6nR6cg8epsnG3kczC8PV0P","service":"spop","name":"Questa nostra grande storia d'amore","artist":"Daniela Ligorio","album":"Una canzone per te, vol. 1","type":"song","duration":234,"albumart":"https://i.scdn.co/image/ab67616d0000b2732f6ae08ea28c92548c9082f0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5g2HNGrMyjTK8mwYs5PswH","service":"spop","name":"Lupi solitari","artist":"Daniela Ligorio","album":"Una canzone per te, vol. 1","type":"song","duration":242,"albumart":"https://i.scdn.co/image/ab67616d0000b2732f6ae08ea28c92548c9082f0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:05 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3rZpkC90y5YHN2q615MudW","service":"spop","name":"Per te","artist":"Daniela Ligorio","album":"Una canzone per te, vol. 1","type":"song","duration":213,"albumart":"https://i.scdn.co/image/ab67616d0000b2732f6ae08ea28c92548c9082f0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:06 motivo volumio[929]: info: Initializing connection to go-librespot Websocket
Apr 29 14:41:06 motivo volumio[929]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 29 14:41:06 motivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 29 14:41:06 motivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 68.
Apr 29 14:41:06 motivo systemd[1]: Stopped go-librespot Daemon.
Apr 29 14:41:06 motivo systemd[1]: Started go-librespot Daemon.
Apr 29 14:41:06 motivo go-librespot[3807]: Librespot-go daemon starting...
Apr 29 14:41:06 motivo go-librespot[3807]: time="2024-04-29T14:41:06+02:00" level=info msg="generated new device id: d2330334c6c61655148824d4b355b07dcb05d8ba"
Apr 29 14:41:06 motivo go-librespot[3807]: time="2024-04-29T14:41:06+02:00" level=debug msg="stored credentials found for brine7q"
Apr 29 14:41:07 motivo go-librespot[3807]: time="2024-04-29T14:41:07+02:00" level=debug msg="obtained new client token: AABufGR7ctHgEDtEXEjvhI7U2yHoDCriX8lh33J2hUT8bEuWNQw4kcj1qLgp2dQpyR7my0ibZZaDtCKm9XMIkCIwax8QJGZZ/yzohf6aiR48uQA1pWO3GjljTTsbumQsFuMHD7nTJ8MFskmDQAX7P96DGKhD1XerlrxUz9/h2bGSNMi4oMrP15dXi/wQ5QKKzMyn9OLv4uV3cd0sl27cRAPiWVWQP9Ew1TqOiRYYxRsoIth2UUTiAKAaUtY="
Apr 29 14:41:07 motivo go-librespot[3807]: time="2024-04-29T14:41:07+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Apr 29 14:41:07 motivo go-librespot[3807]: time="2024-04-29T14:41:07+02:00" level=debug msg="completed keyexchange"
Apr 29 14:41:08 motivo go-librespot[3807]: time="2024-04-29T14:41:08+02:00" level=debug msg="completed challenge"
Apr 29 14:41:08 motivo go-librespot[3807]: time="2024-04-29T14:41:08+02:00" level=debug msg="authenticated as brine7q"
Apr 29 14:41:08 motivo go-librespot[3807]: time="2024-04-29T14:41:08+02:00" level=debug msg="authenticated as brine7q"
Apr 29 14:41:08 motivo go-librespot[3807]: time="2024-04-29T14:41:08+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Apr 29 14:41:09 motivo go-librespot[3807]: time="2024-04-29T14:41:09+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Apr 29 14:41:09 motivo go-librespot[3807]: time="2024-04-29T14:41:09+02:00" level=debug msg="dealer connection opened"
Apr 29 14:41:09 motivo go-librespot[3807]: time="2024-04-29T14:41:09+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336"
Apr 29 14:41:09 motivo go-librespot[3807]: time="2024-04-29T14:41:09+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2"
Apr 29 14:41:09 motivo go-librespot[3807]: time="2024-04-29T14:41:09+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17"
Apr 29 14:41:09 motivo go-librespot[3807]: time="2024-04-29T14:41:09+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0"
Apr 29 14:41:09 motivo go-librespot[3807]: time="2024-04-29T14:41:09+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513"
Apr 29 14:41:09 motivo go-librespot[3807]: time="2024-04-29T14:41:09+02:00" level=debug msg="received connection id: MDQ0YTUwZGUtNWZkOS00YWMzLWFkNTAtNTBkNzA2ZDhlZWZkK2RlYWxlcit0Y3A6Ly9nZXc0LWRlYWxlci1hLXI2c3QuZ2V3NC5zcG90aWZ5Lm5ldDo1NzAwKzY0ODUwRDlFQUI5QkYxNDFGN0RCMkNFQTY5OUFDOUJDMkFEMzEyQTQ3MTc5RjIwMUMxMjQyQzg0NzE3ODQ2Qjg="
Apr 29 14:41:09 motivo volumio[929]: info: Initializing connection to go-librespot Websocket
Apr 29 14:41:09 motivo go-librespot[3807]: time="2024-04-29T14:41:09+02:00" level=debug msg="new websocket client"
Apr 29 14:41:09 motivo volumio[929]: info: Connection to go-librespot Websocket established
Apr 29 14:41:09 motivo go-librespot[3807]: time="2024-04-29T14:41:09+02:00" level=debug msg="put connect state because NEW_DEVICE"
Apr 29 14:41:12 motivo volumio[929]: info: Getting Spotify volume
Apr 29 14:41:12 motivo volumio[929]: info: Spotify volume: 100
Apr 29 14:41:12 motivo volumio[929]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10
Apr 29 14:41:12 motivo volumio[929]: info: CoreCommandRouter::volumioGetState
Apr 29 14:41:12 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:41:12 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 49
Apr 29 14:41:12 motivo volumio[929]: SPOTIFY: SPOTIFY VOLUME 100
Apr 29 14:41:12 motivo volumio[929]: SPOTIFY: VOLUMIO VOLUME 49
Apr 29 14:41:12 motivo volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: true
Apr 29 14:41:12 motivo volumio[929]: info: Setting Spotify Volume from Volumio: 49
Apr 29 14:41:14 motivo volumio[929]: SPOTIFY: SETTING SPOTIFY VOLUME 49
Apr 29 14:41:14 motivo volumio[929]: info: Sending Spotify command with payload to local API: /player/volume
Apr 29 14:41:14 motivo go-librespot[3807]: time="2024-04-29T14:41:14+02:00" level=debug msg="update volume to 32112/65535"
Apr 29 14:41:14 motivo go-librespot[3807]: time="2024-04-29T14:41:14+02:00" level=debug msg="put connect state because VOLUME_CHANGED"
Apr 29 14:41:14 motivo go-librespot[3807]: time="2024-04-29T14:41:14+02:00" level=trace msg="emitting websocket event: volume"
Apr 29 14:41:14 motivo volumio[929]: SPOTIFY: received: {"type":"volume","data":{"value":49,"max":100}}
Apr 29 14:41:14 motivo volumio[929]: SPOTIFY: RECEIVED SPOTIFY VOLUME 49
Apr 29 14:41:19 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri
Apr 29 14:41:19 motivo volumio[929]: info: In handleBrowseUri, curUri=spotify:album:5WUD0byhd6mQvKnPATSwpo
Apr 29 14:41:20 motivo volumio[929]: info: Preload queue cleared
Apr 29 14:41:20 motivo volumio[929]: info: Preloading song: spotify:track:1R3dWMsnDPt9TMQaMzMUBS
Apr 29 14:41:20 motivo volumio[929]: info: Preloading song: spotify:track:5glUL9jOPUDeg3xCp8TUuR
Apr 29 14:41:20 motivo volumio[929]: info: Preloading song: spotify:track:0zvgzgpLMxPWr7fOXCLMx4
Apr 29 14:41:20 motivo volumio[929]: info: Preloading song: spotify:track:5zd9EXZujflINL16eUHgqo
Apr 29 14:41:20 motivo volumio[929]: info: Preloading song: spotify:track:0wgSeUwMFFEFZWncvOiaki
Apr 29 14:41:20 motivo volumio[929]: info: Preloading song: spotify:track:6qzS9z05BpToWrbsDBpUWC
Apr 29 14:41:20 motivo volumio[929]: info: Preloading song: spotify:track:7cUbgyUkr8YXNH29AqPoIk
Apr 29 14:41:20 motivo volumio[929]: info: Preloading song: spotify:track:6WB8HksoM75dft2QNWlfqU
Apr 29 14:41:20 motivo volumio[929]: info: Exploding uri spotify:track:1R3dWMsnDPt9TMQaMzMUBS in service spop
Apr 29 14:41:20 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:1R3dWMsnDPt9TMQaMzMUBS
Apr 29 14:41:20 motivo volumio[929]: info: Exploding uri spotify:track:5glUL9jOPUDeg3xCp8TUuR in service spop
Apr 29 14:41:20 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:5glUL9jOPUDeg3xCp8TUuR
Apr 29 14:41:20 motivo volumio[929]: info: Exploding uri spotify:track:0zvgzgpLMxPWr7fOXCLMx4 in service spop
Apr 29 14:41:20 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:0zvgzgpLMxPWr7fOXCLMx4
Apr 29 14:41:20 motivo volumio[929]: info: Exploding uri spotify:track:5zd9EXZujflINL16eUHgqo in service spop
Apr 29 14:41:20 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:5zd9EXZujflINL16eUHgqo
Apr 29 14:41:21 motivo volumio[929]: info: Exploding uri spotify:track:0wgSeUwMFFEFZWncvOiaki in service spop
Apr 29 14:41:21 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:0wgSeUwMFFEFZWncvOiaki
Apr 29 14:41:21 motivo volumio[929]: info: Exploding uri spotify:track:6qzS9z05BpToWrbsDBpUWC in service spop
Apr 29 14:41:21 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:6qzS9z05BpToWrbsDBpUWC
Apr 29 14:41:21 motivo volumio[929]: info: Executing endpoint getSimilarAlbums
Apr 29 14:41:21 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums
Apr 29 14:41:21 motivo volumio[929]: info: Executing endpoint metavolumio
Apr 29 14:41:21 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 29 14:41:21 motivo volumio[929]: info: Executing endpoint getSimilarAlbums
Apr 29 14:41:21 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums
Apr 29 14:41:21 motivo volumio[929]: info: Exploding uri spotify:track:7cUbgyUkr8YXNH29AqPoIk in service spop
Apr 29 14:41:21 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:7cUbgyUkr8YXNH29AqPoIk
Apr 29 14:41:21 motivo volumio[929]: info: Executing endpoint metavolumio
Apr 29 14:41:21 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 29 14:41:21 motivo volumio[929]: info: Executing endpoint metavolumio
Apr 29 14:41:21 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 29 14:41:21 motivo volumio[929]: info: Executing endpoint metavolumio
Apr 29 14:41:21 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 29 14:41:21 motivo volumio[929]: info: Exploding uri spotify:track:6WB8HksoM75dft2QNWlfqU in service spop
Apr 29 14:41:21 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:track:6WB8HksoM75dft2QNWlfqU
Apr 29 14:41:21 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0zvgzgpLMxPWr7fOXCLMx4","service":"spop","name":"Portatemi Dio","artist":"Vasco Rossi","album":"Bollicine (Remastered)","type":"song","duration":198,"albumart":"https://i.scdn.co/image/ab67616d0000b2735f859d5afb35312b549c59ab","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:21 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1R3dWMsnDPt9TMQaMzMUBS","service":"spop","name":"Bollicine","artist":"Vasco Rossi","album":"Bollicine (Remastered)","type":"song","duration":337,"albumart":"https://i.scdn.co/image/ab67616d0000b2735f859d5afb35312b549c59ab","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:21 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5glUL9jOPUDeg3xCp8TUuR","service":"spop","name":"Una canzone per te","artist":"Vasco Rossi","album":"Bollicine (Remastered)","type":"song","duration":193,"albumart":"https://i.scdn.co/image/ab67616d0000b2735f859d5afb35312b549c59ab","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:21 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5zd9EXZujflINL16eUHgqo","service":"spop","name":"Vita spericolata","artist":"Vasco Rossi","album":"Bollicine (Remastered)","type":"song","duration":283,"albumart":"https://i.scdn.co/image/ab67616d0000b2735f859d5afb35312b549c59ab","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:21 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6WB8HksoM75dft2QNWlfqU","service":"spop","name":"Mi piaci perché","artist":"Vasco Rossi","album":"Bollicine (Remastered)","type":"song","duration":198,"albumart":"https://i.scdn.co/image/ab67616d0000b2735f859d5afb35312b549c59ab","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:21 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7cUbgyUkr8YXNH29AqPoIk","service":"spop","name":"Ultimo domicilio conosciuto","artist":"Vasco Rossi","album":"Bollicine (Remastered)","type":"song","duration":209,"albumart":"https://i.scdn.co/image/ab67616d0000b2735f859d5afb35312b549c59ab","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:21 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0wgSeUwMFFEFZWncvOiaki","service":"spop","name":"Deviazioni","artist":"Vasco Rossi","album":"Bollicine (Remastered)","type":"song","duration":275,"albumart":"https://i.scdn.co/image/ab67616d0000b2735f859d5afb35312b549c59ab","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:21 motivo volumio[929]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6qzS9z05BpToWrbsDBpUWC","service":"spop","name":"Giocala","artist":"Vasco Rossi","album":"Bollicine (Remastered)","type":"song","duration":324,"albumart":"https://i.scdn.co/image/ab67616d0000b2735f859d5afb35312b549c59ab","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Apr 29 14:41:23 motivo volumio[929]: info: Preload queue cleared
Apr 29 14:41:23 motivo volumio[929]: info: CoreCommandRouter::volumioReplaceandPlayItems
Apr 29 14:41:23 motivo volumio[929]: info: CoreStateMachine::ClearQueue
Apr 29 14:41:23 motivo volumio[929]: info: CoreStateMachine::stop
Apr 29 14:41:23 motivo volumio[929]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 29 14:41:23 motivo volumio[929]: info: CoreStateMachine::stPlaybackTimer
Apr 29 14:41:23 motivo volumio[929]: info: CoreStateMachine::updateTrackBlock
Apr 29 14:41:23 motivo volumio[929]: info: CorePlayQueue::getTrackBlock
Apr 29 14:41:23 motivo volumio[929]: info: CoreStateMachine::pushState
Apr 29 14:41:23 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:41:23 motivo volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 29 14:41:23 motivo volumio[929]: info: CoreCommandRouter::volumioPushState
Apr 29 14:41:23 motivo volumio[929]: info: CoreStateMachine::serviceStop
Apr 29 14:41:23 motivo volumio[929]: info: CorePlayQueue::getTrack 13
Apr 29 14:41:23 motivo volumio[929]: info: CoreCommandRouter::serviceStop
Apr 29 14:41:23 motivo volumio[929]: info: Spotify Stop
Apr 29 14:41:23 motivo volumio[929]: SPOTIFY: SPOTIFY STOP
Apr 29 14:41:23 motivo volumio[929]: SPOTIFY: {"status":"play","position":13,"title":"Love Reaction (You Give Me Vibrations)","artist":"Brine","album":"Outer Space Grooves","albumart":"https://i.scdn.co/image/ab67616d0000b27302486f7f52d481aeca4be8c7","uri":"spotify:track:6VltkMtZhr91H9Nmyi1mbM","trackType":"spotify","codec":"ogg","seek":48558,"duration":268,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":true,"repeatSingle":false,"consume":false,"volume":49,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Apr 29 14:41:23 motivo volumio[929]: info: Sending Spotify command to local API: /player/pause
Apr 29 14:41:23 motivo volumio[929]: info: CorePlayQueue::clearPlayQueue
Apr 29 14:41:23 motivo volumio[929]: info: CorePlayQueue::saveQueue
Apr 29 14:41:23 motivo volumio[929]: info: CoreCommandRouter::volumioPushQueue
Apr 29 14:41:23 motivo volumio[929]: info: CoreStateMachine::addQueueItems
Apr 29 14:41:23 motivo volumio[929]: info: CorePlayQueue::addQueueItems
Apr 29 14:41:23 motivo volumio[929]: info: Preload queue cleared
Apr 29 14:41:23 motivo volumio[929]: info: Adding Item to queue: spotify:album:5WUD0byhd6mQvKnPATSwpo
Apr 29 14:41:23 motivo volumio[929]: info: Exploding uri spotify:album:5WUD0byhd6mQvKnPATSwpo in service spop
Apr 29 14:41:23 motivo volumio[929]: SPOTIFY: EXPLODING URI:spotify:album:5WUD0byhd6mQvKnPATSwpo
Apr 29 14:41:23 motivo volumio[929]: info: Updating RAAT Signal Path
Apr 29 14:41:23 motivo volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 49
Apr 29 14:41:23 motivo volumio[929]: info: MCU Signalled Playback Inactive
Apr 29 14:41:23 motivo volumio[929]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 29 14:41:23 motivo volumio[929]: Error: read ECONNRESET
Apr 29 14:41:23 motivo volumio[929]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:209:20) {
Apr 29 14:41:23 motivo volumio[929]: errno: -104,
Apr 29 14:41:23 motivo volumio[929]: code: 'ECONNRESET',
Apr 29 14:41:23 motivo volumio[929]: syscall: 'read'
Apr 29 14:41:23 motivo volumio[929]: }
Apr 29 14:41:23 motivo volumio[929]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 29 14:41:24 motivo sudo[3866]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-29 14:40
Apr 29 14:41:24 motivo sudo[3866]: 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="17fcb754ddd6bd152b01008c46cc4ba1ca48bf35"
VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71"
VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1"
VOLUMIO_BE_VERSION="281cefcd7a302aa7cfba569185cf7aae19b8c376"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="motivo"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Tue 19 Mar 2024 12:11:05 AM CET"
VOLUMIO_VERSION="3.637"
VOLUMIO_HARDWARE="cm4"
VOLUMIO_DEVICENAME="CM4"
VOLUMIO_VENDOR_MODEL="Volumio Motivo"
VOLUMIO_VENDOR="Volumio"
VOLUMIO_MODEL="Motivo"
VOLUMIO_HASH="22ec2298cd64e50884022fe44f728e19"