-- 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"