Bug 66884

Summary:	pa_stream_get_latency return value steadily increases when playing over network
Product:	PulseAudio	Reporter:	Kerrick Staley <bugs>
Component:	clients	Assignee:	pulseaudio-bugs
Status:	RESOLVED MOVED	QA Contact:	pulseaudio-bugs
Severity:	normal
Priority:	medium	CC:	lennart, poncho
Version:	unspecified
Hardware:	Other
OS:	All
Whiteboard:
i915 platform:		i915 features:
Attachments:	Log of the local PulseAudio server, with --log-level=debug, when the issue occurred

Description Kerrick Staley 2013-07-14 01:29:01 UTC

To reproduce:
1. Have two computers, one connected to speakers (the server) and the other running VLC (the client)
2. On the server, append the following two lines to /etc/pulse/system.pa, start Avahi, and run pulse --system --daemon:
load-module module-native-protocol-tcp auth-ip-acl=127.0.0.1;192.168.1.0/24 auth-anonymous=1
load-module module-zeroconf-publish
3. On the client, append the following two lines to /etc/pulse/default.pa, start Avahi, and run pulse --daemon:
load-module module-native-protocol-tcp
load-module module-zeroconf-discover
4. Run VLC on the client, observe the values returned by pa_stream_get_latency in the function vlc_pa_get_latency in the file vlcpulse.c

Expected result:
Values vary within a relatively small range (which is what happens when playing locally).

Actual result:
Values increase directly with time (i.e. after 4 seconds, values are roughly 4 seconds higher than they were initially).

Comment 1 Kerrick Staley 2013-07-14 07:49:32 UTC

I've debugged the issue a bit, and found pa_smoother_get is returning 0, because pa_smoother_set is passing y-values of 0, because calc_time is returning 0, because s->timing_info.sink_usec is a very large value that appears to grow directly with time. More to come...

Comment 2 Tanu Kaskinen 2013-07-14 10:46:40 UTC

This patch might be relevant for this bug: http://cgit.freedesktop.org/pulseaudio/pulseaudio/commit/?id=705d3c28f215bd6899e0e5c3a5ed9a69418afd86

Comment 3 Kerrick Staley 2013-07-20 09:15:43 UTC

That didn't fix the issue :/

Comment 4 Kerrick Staley 2013-07-24 07:21:11 UTC

I've traced the issue further, and found that the value returned by pa_smoother_get at [1] is constant, instead of increasing proportionally to time.

[1] http://cgit.freedesktop.org/pulseaudio/pulseaudio/tree/src/modules/module-tunnel.c?id=ce21dc4348c787535d7990515d7ccacd4a58e029#n504

Comment 5 Kerrick Staley 2013-07-24 10:39:07 UTC

When the issue occurs, the debug log output is flooded with messages like
D: [module-tunnel] protocol-native.c: Implicit underrun of 'audio stream'
D: [module-tunnel] protocol-native.c: Requesting rewind due to rewrite.

Also, it seems that when the issue occurs, u->smoother->px, u->smoother->py, and u->smoother->dp (at [1]) are all 0, and the history_y values are all 0.

[1] http://cgit.freedesktop.org/pulseaudio/pulseaudio/tree/src/modules/module-tunnel.c?id=ce21dc4348c787535d7990515d7ccacd4a58e029#n504

Comment 6 Kerrick Staley 2013-07-24 10:45:52 UTC

Created attachment 82923 [details]
Log of the *local* PulseAudio server, with --log-level=debug, when the issue occurred

Comment 7 Raymond 2014-01-19 14:26:01 UTC

D: [lt-pulseaudio] sink-input.c: Negotiated format: pcm, format.sample_format = "\"float32le\""  format.rate = "48000"  format.channels = "2"  format.channel_map = "\"front-left,front-right\""

any reason to use float32le ?

Comment 8 GitLab Migration User 2018-07-30 10:25:49 UTC

-- GitLab Migration Automatic Message --

This bug has been migrated to freedesktop.org's GitLab instance and has been closed from further activity.

You can subscribe and participate further through the new bug through this link to our GitLab instance: https://gitlab.freedesktop.org/pulseaudio/pulseaudio/issues/413.

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.