Skip to content

Playback doesn't start from the beginning when using Pulseaudio #292

@odiroot

Description

@odiroot

I have noticed, when running Go-Librespot with Pulsaudio backend, sometimes the song doesn't play from the beginning but from somewhere 1s+ from the start.
Reproduced both inside Podman container and directly on Linux.

How to reproduce:

  1. Start Go-Librespot with Pulseaudio backend.
  2. Open Spotify on your phone and switch the device to Go-Librespot.
  3. Play any song (best some song that is audible from the beginning).
  4. The audio will start about 1s (or later) from the beginning.
  5. Click on another song to start playing.
  6. This song will actually play from the very beginning.
  7. Pause the playback, wait a minute or so.
  8. Choose another song to play.
  9. This one will also start playing from about 1s mark.

In short: "cold start" doesn't start playing from 0:00 but somewhere 1s further. "Warm start" starts playing from 0:00 correctly.
Successfully reproduced on two different computers, running on bare OS as well as within a Podman container.
Additionally I couldn't reproduce this behaviour on ALSA backend, only Pulseaudio.


Config used:

device_name: 'go librespot'

audio_backend: pulseaudio

zeroconf_enabled: true
zeroconf_port: 1235

credentials:
  type: zeroconf
  persist_credentials: false

server:
  enabled: true
  address: 0.0.0.0
  port: 3678

Environment (one of the two where I hit the issue):

  • Spotify on Android for remote control.
  • EndeavourOS Linux x86_64 with kernel 6.17.8 for the host machine.
  • Pipewire 1.6.1 for the audio setup.
  • Go-Librespot v0.7.1 (but also happened on earlier versions).

Debug logs:

INFO[0000] running go-librespot 0.7.1                   
DEBU[0000] app state loaded                             
DEBU[0000] stored credentials not found                 
INFO[0000] api server listening on [::]:3678            
DEBU[0000] fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80] 
DEBU[0000] fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443] 
DEBU[0000] fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443] 
INFO[0000] zeroconf server listening on port 1235       
INFO[0000] using built-in mDNS responder                
DEBU[0015] obtained new client token: <REDACTED> 
DEBU[0016] connected to ap-gue1.spotify.com:4070        
DEBU[0016] completed keyexchange                        
DEBU[0016] completed challenge                          
INFO[0017] authenticated AP                              username="<REDACTED>"
INFO[0017] authenticated Login5                          username="<REDACTED>"
INFO[0017] accepted zeroconf from <REDACTED>               username="<REDACTED>"
DEBU[0017] dealer connection opened                     
DEBU[0017] skipping packet PacketTypeSecretBlock, len: 336 
DEBU[0017] skipping packet PacketTypeLicenseVersion, len: 2 
DEBU[0017] skipping packet PacketTypeUnknown1f, len: 17 
DEBU[0017] skipping packet PacketTypeLegacyWelcome, len: 0 
DEBU[0017] skipping packet PacketTypeMercuryEvent, len: 481 
DEBU[0017] received connection id: YzFmZWViZGYtYjBh...Nzg1Mzc2MDhEMQ== 
DEBU[0017] put connect state because NEW_DEVICE         
DEBU[0017] update volume requested to 65535/65535       
DEBU[0017] put connect state because VOLUME_CHANGED     
DEBU[0017] handling transfer player command from 253dbd4e1e963710074b6207f97b1461116841f8 
DEBU[0022] handling play player command from 253dbd4e1e963710074b6207f97b1461116841f8 
DEBU[0022] resolved context of track                     uri="spotify:search"
DEBU[0022] loading track (paused: false, position: 0ms)  uri="spotify:track:1rOlTL4pKQ9Y1fURua4AJR"
DEBU[0022] put connect state because PLAYER_STATE_CHANGED 
DEBU[0022] selected format OGG_VORBIS_320 (f74106f469b8bb74f43a001d8dba6acd7b0d8b1e)  uri="spotify:track:1rOlTL4pKQ9Y1fURua4AJR"
DEBU[0022] requested aes key for file f74106f469b8bb74f43a001d8dba6acd7b0d8b1e, gid: 1rOlTL4pKQ9Y1fURua4AJR 
DEBU[0022] fetched first chunk of 20, total size is 10370368 bytes  uri="spotify:track:1rOlTL4pKQ9Y1fURua4AJR"
INFO[0022] loaded track "My Body Is a Cage" (paused: false, position: 0ms, duration: 287240ms, prefetched: false)  uri="spotify:track:1rOlTL4pKQ9Y1fURua4AJR"
DEBU[0022] fetched chunk 2/19, size: 524288              uri="spotify:track:1rOlTL4pKQ9Y1fURua4AJR"
DEBU[0022] fetched chunk 1/19, size: 524288              uri="spotify:track:1rOlTL4pKQ9Y1fURua4AJR"
DEBU[0022] put connect state because PLAYER_STATE_CHANGED 
DEBU[0022] sending successful reply for dealer request  
DEBU[0022] put connect state because PLAYER_STATE_CHANGED 
DEBU[0023] fetched chunk 3/19, size: 524288              uri="spotify:track:1rOlTL4pKQ9Y1fURua4AJR"
DEBU[0027] handling pause player command from 253dbd4e1e963710074b6207f97b1461116841f8 
DEBU[0027] pause track at 6595ms                        
DEBU[0027] put connect state because PLAYER_STATE_CHANGED 
DEBU[0027] sending successful reply for dealer request  
DEBU[0027] put connect state because PLAYER_STATE_CHANGED 

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions