Bug 65703

Trying to reproduce it.
How do we know that the latency increases in order of several seconds ?

Running rygel, and browsing from my Android device UPnP player and playing sound.
Executing from the master branch. Am I missing something here. ?

You're browsing the PulseAudio devices and not just the music files exported by Rygel, right?

p.s.: you'll need to manually load the module-http-protocol-tcp and module-rygel-media-server

No, I was initially browsing just the files exported by Rygel, and was trying to use GstLaunch to browse media monitor source.

Thanks for the heads up, regarding loading the rygel module.

So, I tried browsing pa devices as exposed by rygel,
And for some reason, I am receiving following error for every connect request from my UPnP browser.

(rygel:23376): Rygel-CRITICAL **: Error from pipeline RygelHTTPGstResponse: gstsouphttpsrc.c(922): gst_soup_http_src_finished_cb (): /GstPipeline:RygelHTTPGstResponse/GstBin:transcoder-source/GstSoupHTTPSrc:souphttpsrc1:

I am still investigating it, however if you any reflections.. could let me know!

I was able to reproduce it, First I was assuming that client device buffering would have been issue, however the latency increases with time, it seems the bit rates are different.

Hi Arun,

src/pulsecore/protocol-http.c

function: source_output_push_cb -- seems to be pushing the chunk into outq,
function: source_output_process_msg --seems to be fetching from out queue and doing a do_write for the chunk, into the stream for http.

Seems like atleast 2 threads. Suspecting that there might be sync issue, I put a counter in do write and source_output_push_cb,

At the start - 
do_write, counter = 1
source_output_push_cb, counter = 1

After some time, (around 3 minutes later)

do_write, counter = 6165
source_output_push_cb, counter = 6417
which suggests. that do_write has happened 6165 times, and push into the outq has happened 6417 times.

Clearly in the 2 threads, the sync is not happening, and the difference probably increases linear to time.

Any idea why this must be happening?

Are you counting the number of calls or the number of bytes read/written?

Actually I am just counting the number of times the operation is happening, but thats a nice suggestion to count number of bytes.

I think the total bytes pushed and written are pretty close and appear to be in sync.

At time 't'
Pushed => 184072960
do_write => 184421476

Do you think that is far apart ?

So reducing the "Maximum hw buffer size" to minimal (~0), did bring down the latency by 2 seconds, however the effective latency is still around 16 seconds in my setup.

(In reply to comment #10)
> I think the total bytes pushed and written are pretty close and appear to be
> in sync.
> 
> At time 't'
> Pushed => 184072960
> do_write => 184421476
> 
> Do you think that is far apart ?

Assuming 44100 Hz 16-bit 2-channel audio, that's 2 seconds.

Following up on this, I notice that http streamed audio being played at client at 1411Kbps, i.e. 1.4 Mbps, which I think is too high, atleast for Wifi networks. I am running the test on a plain Ad-hoc network, and streaming audio WITHOUT using rygel (direct PA source over http), Windows Media Player isn't able to play the stream over network without any buffering. Additionally if I increase buffering to 2 seconds at the WM Player, the sounds comes broken.

I think compressing the audio might be a solution to this.

There are a few points of latency in this. The first is in PulseAudio, there's some in the network itself (but this is relatively low), and then there's some in the UPnP client itself.

You could probably eliminate the client buffering (or at least make it deterministic) by just opening the HTTP stream directly (look at http://localhost:4714/).

I am able to reproduce some large latency with this as well on my laptop, so this eliminates both the network and the client to some extent, but is still in the "few seconds" range, which is not that great.

Now the latency in PulseAudio is basically caused by points where we are buffering data, so this should be something to look at.

>You could probably eliminate the client buffering (or at least make it >deterministic) by just opening the HTTP stream directly (look at >http://localhost:4714/).
>

Yes, absolutely, so in my experiment described in Commend 13, I was accessing directly the sound cards as exposed by PA over HTTP, without Rygel. However, by setting the client buffering to 0 or as low as 2 seconds, I wasn't able to play the sound perfectly.
Moreover I found that my client (Windows Media Player), was playing the stream at 1411 Kbps, which is the bitrate for uncompressed sound.

Does this suggest that we should apply compression at PulseAudio..?

(In reply to comment #15)
> >You could probably eliminate the client buffering (or at least make it >deterministic) by just opening the HTTP stream directly (look at >http://localhost:4714/).
> >
> 
> Yes, absolutely, so in my experiment described in Commend 13, I was
> accessing directly the sound cards as exposed by PA over HTTP, without
> Rygel. However, by setting the client buffering to 0 or as low as 2 seconds,
> I wasn't able to play the sound perfectly.
> Moreover I found that my client (Windows Media Player), was playing the
> stream at 1411 Kbps, which is the bitrate for uncompressed sound.
> 
> Does this suggest that we should apply compression at PulseAudio..?

Your localhost network should easily cope with the 1.4 Mbps, so this is unlikely to be the culprit.

That's not to say comrpession is not desirable (although doing that in PA itself is not ideal), but the bandwidth problem should be orthogonal to the latency being this large.

> 
> That's not to say comrpession is not desirable (although doing that in PA
> itself is not ideal), but the bandwidth problem should be orthogonal to the
> latency being this large.

However, the buffering is definitely at client end. Because I did the following.

a) Exposed sound cards using rygel, and also directly through http.
b) Connected from my Android device and started streaming, with around 16 second latency.
c) Simply power-offed the system, removing any trace of PA and rygel, however my Android device kept playing the sound, until 16 seconds, and then the stream just died.

So, the client essentially has the stream buffered for 16 seconds.

(In reply to comment #6)
> I was able to reproduce it, First I was assuming that client device
> buffering would have been issue, however the latency increases with time, it
> seems the bit rates are different.

Hi Amar Akshat,

please correct me if there's misunderstanding. I knew littlbe about uPnp and Rygel, even i donot setup the environment to reproduce this issue yet. After some google search and study, i assume the whole picture like below:

1) you're using some Andorid based uPnp player(like BubbleUPnP or other) as control point and player software.
2) Rygel was running and you could get exported media files from other uPnp devices through uPnp player.
3) Pa could export devices in the DLNA network, maybe local device or other uPnp deivce has audio playback capability.
4) uPnp player could see above PA devices through Rygel system.
5) uPnpn player could choose media files and play them through previous exported PA device.

In software level, i assume some operations like below:
1) Rygel get media data and send them to Gstreamer
2) Media data routed to Pulesaudio and send out to selected PA sink through
   http-protocol. The issue is high latency here.

Still i donot quite understand the role of module-rygel-media-server here.
i need some time to get things clear. please let me know whether something was wrong.

thanks
--xingchao

(In reply to comment #17)
> > 
> > That's not to say comrpession is not desirable (although doing that in PA
> > itself is not ideal), but the bandwidth problem should be orthogonal to the
> > latency being this large.
> 
> However, the buffering is definitely at client end. Because I did the
> following.
> 
> a) Exposed sound cards using rygel, and also directly through http.
> b) Connected from my Android device and started streaming, with around 16
> second latency.
> c) Simply power-offed the system, removing any trace of PA and rygel,
> however my Android device kept playing the sound, until 16 seconds, and then
> the stream just died.
> 
> So, the client essentially has the stream buffered for 16 seconds.

what's the expected behavior here after step c) ?
After power-offed, the connection died so if no buffering at client end user could hear nothing, right?
And now android device continue sending left buffering stream out for default device(andoird itself) until all buffering data empty.

So the issue is maybe PA blocked the transferring and caused the high latency.
I mean if PA is fast enough or ready to accept any buffering stream from client end, the buffering stream length in client end should be always 0. 

thanks
--xingchao

(In reply to comment #14)
> There are a few points of latency in this. The first is in PulseAudio,
> there's some in the network itself (but this is relatively low), and then
> there's some in the UPnP client itself.
> 
> You could probably eliminate the client buffering (or at least make it
> deterministic) by just opening the HTTP stream directly (look at
> http://localhost:4714/).
> 
> I am able to reproduce some large latency with this as well on my laptop, so
> this eliminates both the network and the client to some extent, but is still
> in the "few seconds" range, which is not that great.
> 
> Now the latency in PulseAudio is basically caused by points where we are
> buffering data, so this should be something to look at.

Hi Arun/Amar Akshat,

Do you have guide to reproduce this issue within a simple test environment?
I donot have uPnp devices and no Rygel setup yet. But i think if focus on Pa's 
http-module and module-rygel-media-server, maybe can find new clues. According to comment#17, sounds PA was blocked by something strange and client buffering increased to a high latency value. 

So if we can reproduce/test this issue within a simple model, it should be convenient to reproduce it.

--xingchao

(In reply to comment #14)
> There are a few points of latency in this. The first is in PulseAudio,
> there's some in the network itself (but this is relatively low), and then
> there's some in the UPnP client itself.
> 
> You could probably eliminate the client buffering (or at least make it
> deterministic) by just opening the HTTP stream directly (look at
> http://localhost:4714/).
> 
> I am able to reproduce some large latency with this as well on my laptop, so
> this eliminates both the network and the client to some extent, but is still
> in the "few seconds" range, which is not that great.
> 
> Now the latency in PulseAudio is basically caused by points where we are
> buffering data, so this should be something to look at.

Hi Arun/Amar Akshat,

Do you have guide to reproduce this issue within a simple test environment?
I donot have uPnp devices and no Rygel setup yet. But i think if focus on Pa's 
http-module and module-rygel-media-server, maybe can find new clues. According to comment#17, sounds PA was blocked by something strange and client buffering increased to a high latency value. 

So if we can reproduce/test this issue within a simple model, it should be convenient to reproduce it.

--xingchao

Hi Xingchao,

Forget the rygel factor for a minute. Concentrate on http-module, and the delay due to that.

So, you need to, 
-- fetch the master branch
-- build the code, and run ./src/pulseaudio -vvvv
-- load http module, ./src/pactl load-module module-http-protocol-tcp
-- now make sure if the module is loaded by visiting, localhost:4714
-- If you see sources and sinks, you would be able to grab the http link to them by copying the link from the page.

Suppose you try sink(monitor), then you would you have something like

http://localhost:4714/listen/source/alsa_output.pci-0000_00_1b.0.analog-stereo.monitor

Now, you can play the above source on a VLC player, or using gstreamer tools like gst-launch.

I would suggest, try streaming on the local machine, to eliminate any latency caused due to network.

Hope this helps.

Amar

(In reply to comment #19)
> (In reply to comment #17)
> > > 
> > > That's not to say comrpession is not desirable (although doing that in PA
> > > itself is not ideal), but the bandwidth problem should be orthogonal to the
> > > latency being this large.
> > 
> > However, the buffering is definitely at client end. Because I did the
> > following.
> > 
> > a) Exposed sound cards using rygel, and also directly through http.
> > b) Connected from my Android device and started streaming, with around 16
> > second latency.
> > c) Simply power-offed the system, removing any trace of PA and rygel,
> > however my Android device kept playing the sound, until 16 seconds, and then
> > the stream just died.
> > 
> > So, the client essentially has the stream buffered for 16 seconds.
> 
> what's the expected behavior here after step c) ?
If client had no buffering, and given the delay in PA, the sound would have immediately stopped at the client side (or maximum in 1-2 seconds).
The sound keeps playing for 16 seconds in the Client, suggests without reasonable doubt that client is buffering.

(In reply to comment #18)
> (In reply to comment #6)
> > I was able to reproduce it, First I was assuming that client device
> > buffering would have been issue, however the latency increases with time, it
> > seems the bit rates are different.
> 
> Hi Amar Akshat,
> 
> please correct me if there's misunderstanding. I knew littlbe about uPnp and
> Rygel, even i donot setup the environment to reproduce this issue yet. After
> some google search and study, i assume the whole picture like below:
> 
> 1) you're using some Andorid based uPnp player(like BubbleUPnP or other) as
> control point and player software.

I was using, UPnP Play from Cybergarage.

> 2) Rygel was running and you could get exported media files from other uPnp
> devices through uPnp player.
> 3) Pa could export devices in the DLNA network, maybe local device or other
> uPnp deivce has audio playback capability.
> 4) uPnp player could see above PA devices through Rygel system.
> 5) uPnpn player could choose media files and play them through previous
> exported PA device.
> 
> In software level, i assume some operations like below:
> 1) Rygel get media data and send them to Gstreamer
> 2) Media data routed to Pulesaudio and send out to selected PA sink through
>    http-protocol. The issue is high latency here.
> 
> Still i donot quite understand the role of module-rygel-media-server here.
> i need some time to get things clear. please let me know whether something
> was wrong.

Yes, before the rygel factor we need to identify the latency due to the plain streaming over http.
So, you don't really need to use rygel module and any UPNP client to be able to reproduce it.

(In reply to comment #22)
> Hi Xingchao,
> 
> Forget the rygel factor for a minute. Concentrate on http-module, and the
> delay due to that.
> 
> So, you need to, 
> -- fetch the master branch
> -- build the code, and run ./src/pulseaudio -vvvv
> -- load http module, ./src/pactl load-module module-http-protocol-tcp
> -- now make sure if the module is loaded by visiting, localhost:4714
> -- If you see sources and sinks, you would be able to grab the http link to
> them by copying the link from the page.
> 
> Suppose you try sink(monitor), then you would you have something like
> 
> http://localhost:4714/listen/source/alsa_output.pci-0000_00_1b.0.analog-
> stereo.monitor
> 
> Now, you can play the above source on a VLC player, or using gstreamer tools
> like gst-launch.
> 
> I would suggest, try streaming on the local machine, to eliminate any
> latency caused due to network.
> 
> Hope this helps.
> 
> Amar

Hi Amar Akshat,

Thanks your guide.
Now i can see the sinks and source under "http://localhost:4714/listen".
i'm using Intel's ivybridge with codec "Realtek ALC889", also there's HDMI codec too.

The output info is like:
Sinks

Built-in Audio Analog Stereo

Sources

Built-in Audio Analog Stereo

And i think it's ready to use VLC player to play some mp3 files now.
I found VLC has network media option, and should i paste above sink link there?

The sink location is:
http://localhost:4714/listen/source/alsa_output.pci-0000_00_1b.0.analog-stereo.monitor

How did you continue test in your side?

thanks
--xingchao

gst-launch-1.0 souphttpsrc location=<uri> ! decodebin ! pulsesink

(gst-launch-0.10 and decodebin2 if you have gstreamer 0.10)

i add some configuration in VLC player:
1> open media file and choose one MP3 music file, configure it as stream.
2> in destination setup, choose "HTTP", and "NEXT", in the path field,
i should paste the sink location for PA, right?
What about the port number, should be changed to 4714?
3> goto next and start "stream".

please correct me if any step wrong.

(In reply to comment #26)
> gst-launch-1.0 souphttpsrc location=<uri> ! decodebin ! pulsesink
> 
> (gst-launch-0.10 and decodebin2 if you have gstreamer 0.10)

Thanks but seems this doesnot work well, i met some new errors;
gst-launch-0.10 -v souphttpsrc location=/home/xingchao/tmp/1299597316159.mp3 ! decodebin2 ! pulsesink
Setting pipeline to PAUSED ...
Pipeline is PREROLLING ...
ERROR: from element /GstPipeline:pipeline0/GstSoupHTTPSrc:souphttpsrc0: Error parsing URL.
Additional debug info:
gstsouphttpsrc.c(1130): gst_soup_http_src_build_message (): /GstPipeline:pipeline0/GstSoupHTTPSrc:souphttpsrc0:
URL: /home/xingchao/tmp/1299597316159.mp3
ERROR: pipeline doesn't want to preroll.
Setting pipeline to NULL ...
Freeing pipeline ...

Please note it doesnot work either even i add "proxy" parameger for souphttpsrc.

thanks
--xingchao

(In reply to comment #28)
> (In reply to comment #26)
> > gst-launch-1.0 souphttpsrc location=<uri> ! decodebin ! pulsesink

meanwhile i found "souphttpsrc" works well with "filesink":

$ gst-launch-0.10 -v souphttpsrc location=https://bugs.freedesktop.org/show_bug.cgi?id=65703 ! filesink location=/home/xingchao/gst-launch-test.html
Setting pipeline to PAUSED ...
Pipeline is PREROLLING ...
Pipeline is PREROLLED ...
Setting pipeline to PLAYING ...
New clock: GstSystemClock
Got EOS from element "pipeline0".
Execution ended after 430978498 ns.
Setting pipeline to PAUSED ...
Setting pipeline to READY ...
Setting pipeline to NULL ...
Freeing pipeline ...
$ ls gst-launch-test.html 
gst-launch-test.html

And it doesnot need "proxy" setting, it may use system proxy by default.

(In reply to comment #28)
> (In reply to comment #26)
> > gst-launch-1.0 souphttpsrc location=<uri> ! decodebin ! pulsesink
> > 
> > (gst-launch-0.10 and decodebin2 if you have gstreamer 0.10)
> 
> Thanks but seems this doesnot work well, i met some new errors;
> gst-launch-0.10 -v souphttpsrc location=/home/xingchao/tmp/1299597316159.mp3
> ! decodebin2 ! pulsesink

location needs to be an HTTP URI.

(In reply to comment #30)
> (In reply to comment #28)
> > (In reply to comment #26)
> > > gst-launch-1.0 souphttpsrc location=<uri> ! decodebin ! pulsesink
> > > 
> > > (gst-launch-0.10 and decodebin2 if you have gstreamer 0.10)
> > 
> > Thanks but seems this doesnot work well, i met some new errors;
> > gst-launch-0.10 -v souphttpsrc location=/home/xingchao/tmp/1299597316159.mp3
> > ! decodebin2 ! pulsesink
> 
> location needs to be an HTTP URI.

so if the location is "Source" exported by PA, could hear loopback audio, right?
The source location is "http://localhost:4714/listen/source/alsa_input.pci-0000_00_1b.0.analog-stereo".

(In reply to comment #31)
> so if the location is "Source" exported by PA, could hear loopback audio,
> right?
> The source location is
> "http://localhost:4714/listen/source/alsa_input.pci-0000_00_1b.0.analog-
> stereo".

Right.

(In reply to comment #32)
> (In reply to comment #31)
> > so if the location is "Source" exported by PA, could hear loopback audio,
> > right?
> > The source location is
> > "http://localhost:4714/listen/source/alsa_input.pci-0000_00_1b.0.analog-
> > stereo".
> 
> Right.

I used "arecord" to capture a piece of wav, it works well.
But when try to test the source, there's error, and cannot hear voice from Mic:

$gst-launch-0.10 -v souphttpsrc location=http://localhost:4714/listen/source/alsa_input.pci-0000_00_1b.0.analog-stereo ! decodebin2 ! pulsesink
Setting pipeline to PAUSED ...
Pipeline is PREROLLING ...
ERROR: from element /GstPipeline:pipeline0/GstSoupHTTPSrc:souphttpsrc0: Service Unavailable
Additional debug info:
gstsouphttpsrc.c(1119): gst_soup_http_src_parse_status (): /GstPipeline:pipeline0/GstSoupHTTPSrc:souphttpsrc0:
Service Unavailable (503), URL: http://localhost:4714/listen/source/alsa_input.pci-0000_00_1b.0.analog-stereo
ERROR: pipeline doesn't want to preroll.
Setting pipeline to NULL ...
/GstPipeline:pipeline0/GstDecodeBin2:decodebin20/GstTypeFindElement:typefind.GstPad:src: caps = text/html
/GstPipeline:pipeline0/GstDecodeBin2:decodebin20/GstTypeFindElement:typefind.GstPad:src: caps = NULL
Freeing pipeline ...

Hi Akshat,

As i cannot reproduce the high latency issue atm, so would you share with me the pulseaudio infomathin when you do the test on your side?

pacmd--> info.

i wonder check the http-protocol client's status.

--xingchao

i would reproduce the issue on another machine later.
before that, i hope no misunderstanding from my side about the data path in below test command:
gst-launch-0.10 -v playbin uri=http://localhost:4714/listen/source/alsa_input.pci-0000_00_1b.0.analog-stereo

In such scenario, gst-launch would be the client for http_protocol, so the data path would be:
1> gst-launch try to read data from the exported source by PA, it's an http url.
2> pulseaudio regard gst-launch as the client connected to PA, also it's the target of source_out.
3> pulseaudio got data from Source and send to gst-launch
4> gst-launch buffer the data and send back to PA as the role of sink_input.
5> user hear captured audio from sink.

please correct me if any step wrong above.

--xingchao

(In reply to comment #35)
> i would reproduce the issue on another machine later.

I think i reproduced the issue now.
With same command on another laptop, i can long time delay after starting playing:

gst-launch playbin uri=http://localhost:4714/listen/source/alsa_input.pci-0000_00_1b.0.analog-stereo

$ gst-launch-0.10 playbin uri=http://localhost:4714/listen/source/alsa_input.pci-0000_00_1b.0.analog-stereo
Setting pipeline to PAUSED ...
Pipeline is PREROLLING ...
buffering... 0%  
buffering... 0%  
...
Pipeline is PREROLLED ...
Setting pipeline to PLAYING ...
New clock: GstPulseSinkClock
Buffering, setting pipeline to PAUSED ...
Done buffering, setting pipeline to PLAYING ...
...
Prerolled, waiting for buffering to finish...
Done buffering, setting pipeline to PLAYING ...
handling interrupt.
Interrupt: Stopping pipeline ...
Execution ended after 1254077037 ns.
Setting pipeline to PAUSED ...
Setting pipeline to READY ...
Setting pipeline to NULL ...
Freeing pipeline ...


However the latency is larger than 16seconds here.
i would continue to investigate on that.
--xingchao

Note that playbin does buffering of its own, which is why I suggested the souphttpsrc + decodebin pipeline.

(In reply to comment #37)
> Note that playbin does buffering of its own, which is why I suggested the
> souphttpsrc + decodebin pipeline.

Oh good that explain much. :)

(In reply to comment #14)
> There are a few points of latency in this. The first is in PulseAudio,
> there's some in the network itself (but this is relatively low), and then
> there's some in the UPnP client itself.
> 
> You could probably eliminate the client buffering (or at least make it
> deterministic) by just opening the HTTP stream directly (look at
> http://localhost:4714/).
> 
> I am able to reproduce some large latency with this as well on my laptop, so
> this eliminates both the network and the client to some extent, but is still
> in the "few seconds" range, which is not that great.
> 
> Now the latency in PulseAudio is basically caused by points where we are
> buffering data, so this should be something to look at.

Arun, how did you reproduce this issue here? 
did you use command at comment #26?
gst-launch-1.0 souphttpsrc location=<uri> ! decodebin ! pulsesink

--xingchao

Arun,

could you try below command at your side?

gst-launch-0.10 souphttpsrc location=http://www.mediacollege.com/audio/tone/files/250Hz_44100Hz_16bit_30sec.wav ! decodebin ! pulsesink

I can hear sound at about ~2 seconds delay.

And compared with gst-launch, i used "mplayer" to repeat test, the delay is longer, ~4s.
That's caused by cache in mplayer:
"Cache size set to 320 KBytes
Cache fill: 12.62% (41368 bytes)   
"

So for me, this issue behavior is different:
1> with gst-launch playbin, comment #36.
gst-launch playbin uri=http://localhost:4714/listen/source/alsa_input.pci-0000_00_1b.0.analog-stereo
very long time delay. as your suggestion, switch to use souphttpsrc
2> with soupthttpsrc, the delay is ~2s, i think that's acceptable.

--xingchao

(In reply to comment #40)
> Arun,
> 
> could you try below command at your side?
> 
> gst-launch-0.10 souphttpsrc
> location=http://www.mediacollege.com/audio/tone/files/
> 250Hz_44100Hz_16bit_30sec.wav ! decodebin ! pulsesink
> 
> I can hear sound at about ~2 seconds delay.
> 
> And compared with gst-launch, i used "mplayer" to repeat test, the delay is
> longer, ~4s.
> That's caused by cache in mplayer:
> "Cache size set to 320 KBytes
> Cache fill: 12.62% (41368 bytes)   
> "
> 
> So for me, this issue behavior is different:
> 1> with gst-launch playbin, comment #36.
> gst-launch playbin
> uri=http://localhost:4714/listen/source/alsa_input.pci-0000_00_1b.0.analog-
> stereo
> very long time delay. as your suggestion, switch to use souphttpsrc
> 2> with soupthttpsrc, the delay is ~2s, i think that's acceptable.
> 
> --xingchao

As the playback has almost no latency, i suspect the latency coming from the capture routine:
gst-launch-0.10 souphttpsrc location=http://localhost:4714/listen/source/alsa_input.pci-0000_00_1b.0.analog-stereo ！ decodebin ! pulsesink
(This test command doesnot work for me, there's error)
And in such scenario, the data path is like:

capture data-->PA Source-->http-protocol-->bin-->buffer?-->native-protocol-->PA-->Sink

currently i'm blocked by above test command, it doesnot work for me.

thanks
--xingchao

Amar,

did you tune the parameter of decodebin? i'm suspecting below parameters may has impact on the latency:
  "high-percent"            
  "low-percent"            
  "max-size-buffers"       
  "max-size-bytes"          
  "max-size-time"         

--xingchao

Created attachment 82062 [details] [review]
patch to debug http latency issue

The bug is about server side latency. Client side latency is something we don't have much control over. It is usually easy enough to generate additional latency by doing a few pause/resume cycles on the playback stream.

Also, I got something in the range of 5 seconds in my testing. 2 seconds is still not good - think of someone playing music from their laptop to a UPnP device. You don't want it to take 2s between hitting "next" and the track actually switching.

(In reply to comment #45)
> Also, I got something in the range of 5 seconds in my testing. 2 seconds is
> still not good - think of someone playing music from their laptop to a UPnP
> device. You don't want it to take 2s between hitting "next" and the track
> actually switching.

Yeah agree. 2 seconds is also long enough. Sometimes user may feel unacceptable.
i want to ensure the where the latency coming from. Maybe it's in http-protocol inside or from buffering in bin.

How to reproduce this issue in local machine-:

1. pulseaudio --k; pulseaudio -vvvv
2. pactl load-module module-http-protocol-tcp
3. browser sinks/sources in Fixfox, url is:
http://localhost:4714/listen
will show sinks and sources
As I enabled Rygel following this page(https://wiki.gnome.org/Rygel/Pulseaudio), so there're two Sinks:

Built-in Audio Analog Stereo
DLNA/UPnP Streaming

And one Sources

Built-in Audio Analog Stereo

4. The basic rule is, playback music on one sink 0, and featch stream from sink 0 and send back to sink 1. 
  Here's my test command:
  1) gst-launch-0.10 filesrc location=/home/tangtang/Downloads/b.mp3 ! mad ! audioconvert ! audioresample ! pulsesink device=upnp
  this would send mp3 stream to sink "upnp"
  2) gst-launch-0.10 souphttpsrc location=http://localhost:4714/listen/source/upnp.monitor ! decodebin2 ! pulsesink device=alsa_output.pci-0000_00_1b.0.analog-stereo
  this would featch stream from sink "upnp" and send data back to default sink(user could hear music)

it's better to start second command and you when you start first command, after some delay, you will hear the music playing.  If you stop first command, you will notice music continues playing for some time and stopped.

--xingchao

Created attachment 82081 [details]
http-latency issue log

This log starts from playing back on sink 0,  and stops on terminate playing back on sink 1.

So can continue to investigate the latency during the test.

Created attachment 82082 [details]
this is the correct/full log, ignore previous log

Created attachment 82117 [details] [review]
add missing rewind callback

seems the source_output donot take rewind callback, and this make connection's output_memblockq never stop sending out useless data. So if user press "pause" but the stream would still send out to client.

I have a new patch to fix the issue.
The rootcause is about rewind missing in protcol-http, that caused the memblockq always has old stream even sink/monitor_source have flushed their data.
And it would cause two obvious latency;
- when starting to playback stream.
The latency is "silence" before user hear the stream
- when cork or stop the stream
The latency is from old stream data in memblockq.

After adding rewind callback, both the latency reduced to acceptable range.

--xingchao

Created attachment 82132 [details] [review]
0001-protocol-http-Add-missing-rewind-callback-for-source.patch

first patch to add rewind callback

Created attachment 82133 [details] [review]
0002-protocol-http-Fix-assertion-in-do_write.patch

second patch to fix assertion error.

Arun/Amar,

The two patches could help reduce latency as my test shown in comment#47.
0001-protocol-http-Add-missing-rewind-callback-for-source.patch
0002-protocol-http-Fix-assertion-in-do_write.patch

Please let me know whether it works for you.

--xingchao

I tested this on the release version of pulseaudio on Ubuntu 12.04 (wiz 1.0), and I noticed the latency dropped by almost 1 to 1.5 seconds. However, I guess, there is still some element of un-acceptability in the existing latency.

for some some reason, I am unable to test on master, and the latency is still the same. Will update, as soon as I have some success testing on master.

Please note that I am re-producing it as described in comment 47.

I very much doubt that adding a rewind callback is the correct fix. The reason is that nothing in the code base currently implements the source output process_rewind() callback, so it doesn't seem to be important (I don't fully understand how source rewinding works - it's quite different from sink rewinding).

Also, source outputs can be rewound only when connected to a monitor source. Are you using a monitor source for testing? If not, then the callback is never called. How can the patch then have any effect on the latency? It seems that pa_source_output_push() behaves differently if the process_rewind() callback is set (even if it's never called):

    limit = o->process_rewind ? 0 : o->source->thread_info.max_rewind;

Adding to what Tanu said, the latency really is much more likely to be in the HTTP module itself.

(In reply to comment #56)
> I very much doubt that adding a rewind callback is the correct fix. The
> reason is that nothing in the code base currently implements the source
> output process_rewind() callback, so it doesn't seem to be important (I
> don't fully understand how source rewinding works - it's quite different
> from sink rewinding).
> 
> Also, source outputs can be rewound only when connected to a monitor source.
> Are you using a monitor source for testing?

yes, the source outputs connected to the monitor source "upnp" in the test case. please look at comment #47.
And it's easy to reproduce the issue with comment#47, you can check from the log the callback was called, and the latency reduced effeciently.i.e. without the patch, when stop the first stream which rendering MP3 to monitor source, i still hear musck playing for almost ~2 seconds. With the patch applied, it would shtop playback immediately.


> If not, then the callback is
> never called. How can the patch then have any effect on the latency? It
> seems that pa_source_output_push() behaves differently if the
> process_rewind() callback is set (even if it's never called):
> 
>     limit = o->process_rewind ? 0 : o->source->thread_info.max_rewind;

Ok, I'll have a deeper look into the patch, and try to really understand what it does (I'm not very eager to work on this bug myself, but I try to review any patches that are sent).

I think I have now a bit better idea of how source rewinding works. I still don't think that setting a rewind callback for the source output implementation is a good idea. It does reduce the latency, because data doesn't get buffered in pa_source_output.thread_info.delay_memblock if the callback is set. However, the delay_memblockq exists for a reason: clients can't handle the stream time going backwards, which is what happens on rewinds, so there must be a buffer somewhere that hides the rewind events from clients. If you disable the buffer in pa_source_output, you should implement a similar buffer in protocol-http, but your patch doesn't implement that. The result is that your patch most likely causes non-continuities in the audio, when rewinds occur.

If the latency caused by the delay memblockq is too large, the solution is to request lower latency from the source output. This should reduce the maximum rewind size, and therefore also the size of the delay memblockq.

-- 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/139.