<html> <head> <meta content="text/html; charset=utf-8" http-equiv="Content-Type"> </head> <body bgcolor="#FFFFFF" text="#000000"> <div class="moz-cite-prefix">On 09.04.2016 03:29, Raymond Yau wrote: </div> <blockquote cite="mid:CAN8cciZs2dqe-J=D0vJ3LG-xAkeeGnV8GA0KQL0Hx51vuo9tQQ@mail.gmail.com" type="cite"> 2016-4-9 上午2:23於 "Georg Chini" <<a moz-do-not-send="true" href="mailto:georg@chini.tk">georg@chini.tk</a>>寫道： > > On 08.04.2016 18:01, Tanu Kaskinen wrote: > >>>>>> >>>>>> I can't follow that line of reasoning. In the beginning the ring buffer >>>>>> is filled to max, and once you call snd_pcm_start(), data starts to >>>>>> move from the ring buffer to other buffers (I'll call the other buffers >>>>>> the "not-ring-buffer"). Apparently the driver "sees" the not-ring- >>>>>> buffer only partially, since it reports a larger latency than just the >>>>>> ring buffer fill level, but it still doesn't report the full latency. >>>>>> The time between snd_pcm_start() and the point where the reported delay >>>>>> does not any more equal the written amount tells the size of the >>>>>> visible part of the not-ring-buffer - it's the time it took for the >>>>>> first sample to travel from the ring buffer to the invisible part of >>>>>> the not-ring-buffer. I don't understand how the time could say anything >>>>>> about the size of the invisible part of the not-ring-buffer. Your logic >>>>>> "works" only if the visible and invisible parts happen to be of the >>>>>> same size. >>>>>> >>>>>> You should get the same results by calculating >>>>>> >>>>>> adjusted delay = ring buffer fill level + 2 * (reported delay - ring buffer fill level) >>>>>> >>>>>> That formula doesn't make sense, but that's how I understand your logic >>>>>> works, with the difference that your fix is based on one measurement >>>>>> only, so it's constant over time, while my formula recalculates the >>>>>> adjustment every time the delay is queried, so the adjustment size >>>>>> varies somewhat depending on the granularity at which audio moves to >>>>>> and from the visible part of the not-ring-buffer. >>>>>> >>>>>> In any case, even if your logic actually makes sense and I'm just >>>>>> misunderstanding something, I don't see why the correction should be >>>>>> done in pulseaudio instead of the alsa driver. >>>>> >>>>> Well, now I don't understand what you mean. The logic is very simple: >>>>> If there is a not reported delay between the time snd_pcm_start() is >>>>> called and the time when the first sample is delivered to the DAC, then >>>>> this delay will persist and become part of the continuous latency. >>>>> That's all, what causes the delay is completely irrelevant. >>>> >>>> The code can't know when the first sample hits the DAC. The delay >>>> reported by alsa is supposed to tell that, but if the reported delay is >>>> wrong, I don't think you have any way to know the real delay. >>> >>> Yes, the code can know when the first sample hits the DAC. I explained it >>> already. Before the first sample hits the DAC, the delay is growing and >>> larger or equal than the number of samples you have written to the >>> buffer. >>> At the moment the delay is smaller than the write count, you can be >>> sure that at least some audio has been delivered. Since the delay is >>> decreased by the amount of audio that has been delivered to the DAC, >>> you can work back in time to the moment when the first sample has been >>> played. >> >> Yes, you explained that already, but you didn't give a convincing >> explanation of why the point in time when the delay stops growing would >> indicate the point when the first sample hit the DAC. > > > See below. The precondition for my thoughts naturally is that no > samples vanish from the latency reports, maybe that is where > we are thinking differently. > > >> >>>>> Maybe what I said above was not complete. At the point in time when >>>>> the first audio is played, there are two delays: First the one that is >>>>> reported >>>>> by alsa and the other is the difference between the time stamps minus >>>>> the played audio. If these two delays don't match, then there is an >>>>> "extra delay" that has to be taken into account. >>>> >>>> The difference between the time stamps is not related to how big the >>>> invisible part of the buffer is. I'll try to illustrate: >>>> >>>> In the beginning, pulseaudio has written 10 ms of audio to the ring >>>> buffer, and snd_pcm_start() hasn't been called: >>>> >>>> DAC <- ssssssssss|sss|dddddddddd <- pulseaudio >>>> >>>> Here "ssssssssss|sss|ddddddddd" is the whole buffer between the DAC and >>>> pulseaudio. It's divided into three parts; the pipe characters separate >>>> the different parts. Each letter represents 1 ms of data. "s" stands >>>> for silence and "d" stands for data. The first part of the buffer is >>>> the invisible part that is not included in the delay reports. I've put >>>> 10 ms of data there, but it's unknown to the driver how big the >>>> invisible part is. The middle part of the buffer is the "send buffer" >>>> that the driver maintains, its size is 3 ms in this example. It's >>>> filled with silence in the beginning. The third part is the ring >>>> buffer, containing 10 ms of data from pulseaudio. >>>> >>>> At this point the driver reports 10 ms latency. It knows it has 3 ms of >>>> silence buffered too, which it should include in its latency report, >>>> but it's stupid, so it only reports the data in the ring buffer. The >>>> driver has no idea how big the invisible part is, so it doesn't include >>>> it in the report. >>>> >>>> Now pulseaudio calls snd_pcm_start(), which causes data to start moving >>>> from the ring buffer to the send buffer. After 1 ms the situation looks >>>> like this: >>>> >>>> DAC <- ssssssssss|ssd|ddddddddd <- pulseaudio >>>> >>>> There's 2 ms of silence in the send buffer and 1 ms of data. The driver >>>> again ignores the silence in the send buffer, and reports that the >>>> delay is 10 ms, which consists of 1 ms of data in the send buffer and 9 >>>> ms of data in the ring buffer. >>>> >>>> After 2 ms: >>>> >>>> DAC <- ssssssssss|sdd|dddddddd <- pulseaudio >>>> >>>> Reported delay: 10 ms >>>> >>>> After 3 ms: >>>> >>>> DAC <- ssssssssss|ddd|ddddddd <- pulseaudio >>>> >>>> Reported delay: 10 ms >>>> >>>> Let's say pulseaudio refills the ring buffer now. >>>> >>>> DAC <- ssssssssss|ddd|dddddddddd <- pulseaudio >>>> >>>> Reported delay: 13 ms >>>> >>>> After 4 ms: >>>> >>>> DAC <- sssssssssd|ddd|ddddddddd <- pulseaudio >>>> >>>> The first data chunk has now entered the invisible part of the buffer, >>>> but it will still take 9 ms before it hits the DAC. At this point >>>> pulseaudio has written 13 ms of audio, and the reported delay is 12 ms. >>>> According to your logic, the adjusted delay is 12 + (4 - 1) = 15 ms, >>>> while in reality the latency is 22 ms. >>> >>> At this point, no audio has been played yet. You still have silence in the >>> buffer, so alsa would not report back, that samples have been played. >> >> But the reported delay stopped growing! That's the point where you >> claim the first sample hits the DAC, but as my example illustrates, >> that doesn't seem to be true. > > > In your example it is not true, that's right. But for the USB devices it is. > They only start decreasing the delay when real audio has been played, > and they would increase the delay when you write to the buffer, > I have checked that in the code. > And I think any driver that makes samples vanish is so severely screwed, > that we can't do anything about it. If the driver reports complete moonshine > numbers, you can't fix it, I agree with you in that respect. > > But that is not the case with USB. There is only some missing latency > that is not reported - call it transport delay or whatever and I suspect a > similar delay can be found in other alsa drivers. There is no need to figure > out the reason for it, it just takes some time after snd_pcm_start() was > called until the first sample is played - without making samples vanish. > And in that case the delay can be detected and used by the code. > > >> >>> I choose the point where the first d hits the DAC and that is reported >>> back by alsa. (see above) I've tried put it all together in a document. >>> I hope I can finish the part that deals with the smoother code today. >>> If so, I will send it to you privately because the part about >>> module-loopback >>> is still missing. >>> Anyway, even if you think it is wrong I am still measuring the correct >>> end-to-end latency with my code, so something I am doing must be >>> right ... >> >> >From what I can tell, that's a coincidence. > > > No, it definitely isn't. If you accept the precondition, that samples > not simply vanish from the latency reports, it's physics. > I would tend to agree that I have overlooked something, if the "extra > delay" would be the same every time and if I could not write down > the math for it. > But it isn't completely constant (just in the same range) and I can > write down the math and it matches my measurements. So I am > fairly sure that I am right. Did you have a look at my document? > > >> >>>> I don't know how well this model reflects the reality of how the usb >>>> audio driver works, but this model seems like a plausible explanation >>>> for why the driver reports delays equalling the amount of written data >>>> in the beginning, and why the real latency is higher than the reported >>>> latency at later times. >>>> >>>> I hope this also clarifies why I don't buy your argument that the time >>>> stamp difference is somehow related to the unreported latency. >>> >>> No, in fact it doesn't. >>> >>>>> Trying to fix up that delay on every iteration does not make any sense >>>>> at all, it is there from the start and it is constant. >>>> >>>> Commenting on "it is constant": The playback latency is the sum of data >>>> in various buffers. The DAC consumes one sample at a time from the very >>>> last buffer, but I presume that all other places move data in bigger >>>> chunks than one sample. The unreported delay can only be constant if >>>> data moves to the invisible part of the buffering in one sample chunks. >>>> Otherwise the latency goes down every time the DAC reads a sample, and >>>> then when the buffer is refilled at the other end, the latency jumps up >>>> by the refill amount. >>> >>> I only said the "extra latency" is constant, not the latency as such. >>> See your own example above that your argument is wrong. Even >>> if the audio is moved in chunks through your invisible buffer part, >>> that part still has the same length all the time. When one "d" is >>> moved forward another one will replace it. >> >> No, the invisible part is not constant, even though my presentation >> didn't show the variance. The DAC consumes data from the invisible >> buffer one sample at a time, and each time it does that, the extra >> latency decreases by one sample. Data moves from the visible part of >> the buffer to the invisible part in bigger chunks. I didn't specify the >> chunk size, but if we assume 1 ms chunks, the extra latency grows by 1 >> ms every time a chunk is transferred from the visible part to the >> invisible part. > > > Then take any part of the buffer but the last or the first bit. All the > chunks are always full, so it's constant. The moving bit is dealt with > elsewhere, (in the smoother) but there is a lot of buffer that is always > full. > And when you take USB, the driver sees only chunks. The sample > by sample consuming of the DAC is never seen by the driver, it gets > the notification from USB that a chunk has been played. > I'm not sure how it is with HDA, but probably similar. > >> >>>>> This is not a negative delay reported by alsa, but my "extra latency" >>>>> is getting negative, which means playback must have started >>>>> before snd_pcm_start(). >>>>> According to Raymond Yau playback seems in fact to be started >>>>> before snd_pcm_start() for HDA devices, at least if I read his last >>>>> mail on that topic right. Then the negative delays would even make >>>>> sense, since data is written to the buffer before snd_pcm_start(). >>>> >>>> I had a look at the code to verify the claim that we configure alsa to >>>> start playback already before we call snd_pcm_start(). If we really do >>>> that intentionally, then it doesn't make sense to call snd_pcm_start() >>>> explicitly. >>>> >>>> This is what we do: >>>> snd_pcm_sw_params_set_start_threshold(pcm, swparams, (snd_pcm_uframes_t) -1) >>>> >>>> Note the casting of -1 to an unsigned integer. It seems that the >>>> intention is to set as high threshold as possible to avoid automatic >>>> starting. However, alsa-lib casts the threshold back to a signed value >>>> when it's used, and I believe the end result is indeed that playback >>>> starts immediately after the first write. I don't know if that matters, >>>> since we do the manual snd_pcm_start() call immediately after the first >>>> write anyway, but it seems like a bug in any case. >> >> Not very important, but I'll clarify one thing: I had another look, and >> I'm not any more sure that the code where I saw the casting back to a >> signed integer is actually used by pulseaudio. The function >> is snd_pcm_write_areas(), but pulseaudio doesn't call that at least >> directly, and I did some searching in alsa-lib too, and I didn't find a >> call path that would cause snd_pcm_write_areas() to be used by >> pulseaudio. Even if snd_pcm_write_areas() isn't used, though, it's >> entirely possible that there's some other code that does a similar >> cast. I don't know the code is that triggers the snd_pcm_start() call >> when the ring buffer fill level exceeds the configured threshold. It >> might be in the kernel. >> >>> OK, this it why I measure an "extra latency" of -60 to -20 usec. >>> So again, if I can measure it and even detect a bug that way, >>> don't you think there must be some truth in what I'm saying? >> >> Do I understand correctly that your "extra latency" is affected by >> whether snd_pcm_start() is called implicitly in mmap_write() or >> explicitly after mmap_write()? The time when mmap_write() is called >> doesn't affect the latency in the long term. > > It does. It isn't much, but if playback starts earlier, the delay > will be exactly that amount less even after 10 hours of playback. > Let's assume you have 10ms of audio to write to the buffer. > During the time, when you write, samples are coming in. > Let's say it takes 100 usec to write the buffer. If you start > playback after the write, this will be 100 usec additional delay. > 5 samples have accumulated. > If you start playback immediately after the first bit of data is > written this might take much less time, say 20 usec. > So your delay is four samples less and it will remain that way > until the sink is stopped. There is nothing that would take away > the delay. > > >> The smoother will produce >> wrong values if it's not started at the same time as snd_pcm_start() is >> called, but I presume the smoother is able to fix such inaccuracies >> over time, so it doesn't matter that much when the snd_pcm_start() is >> called. So isn't it a bad thing if your "extra latency" permanently >> includes something that doesn't have any real effect after some time? > > > Yes, it is affected by it and it should be, because the "extra delay" > is the time between snd_pcm_start() and the first sample being > played. So if the first samples are played before snd_pcm_start() > the "extra latency" will become negative. And as explained above, > it has permanent effect. Somehow you seem to be of the opinion > that all delays that are not controlled by the pulseaudio code > vanish magically, but they don't. > > For the reported latency, it just means, that it will become slightly > smaller. As I said, the smoother does not use the "extra delay" > for anything, it is only calculated once when the origin for the > smoother is set and added later as an offset, when get_latency() > is called. > as your log had two "Starting Playback" message, can you call snd_pcm_dump after snd_pcm_start to find value of appl_ptr, </blockquote> I will, but there is a suspend message between the two "Starting Playback" messages: sink.c: Suspending sink alsa_output.usb-0d8c_C-Media_USB_Headphone_Set-00.analog-stereo due to changing the sample rate. sink.c: Suspend cause of sink alsa_output.usb-0d8c_C-Media_USB_Headphone_Set-00.analog-stereo is 0x0020, suspending So I don't think there is a problem, but I will do your test and let you know the results. <blockquote cite="mid:CAN8cciZs2dqe-J=D0vJ3LG-xAkeeGnV8GA0KQL0Hx51vuo9tQQ@mail.gmail.com" type="cite"> do pulseaudio prebuf mean minimum first write ? </blockquote> Don't know, according to Tanu, the first write will fill the buffer to the configured latency. The log also shows this. Because the buffer of module-loopback is filled when playback is started, buffering should not be a problem. <blockquote cite="mid:CAN8cciZs2dqe-J=D0vJ3LG-xAkeeGnV8GA0KQL0Hx51vuo9tQQ@mail.gmail.com" type="cite"> Do loopback module stop the running pcm stream ? Seem pulseaudio does not use snd_pcm_drop nor snd_pcm_drain, how can the running pcm stream stop? </blockquote> This is the beginning of the suspend function of module-loopback, so obviously snd_pcm_close close is called instead of snd_pcm_drop or _drain (I did not change anything here): static int suspend(struct userdata *u) { pa_assert(u); pa_assert(u->pcm_handle); /* Let's suspend -- we don't call snd_pcm_drain() here since that might * take awfully long with our long buffer sizes today. */ snd_pcm_close(u->pcm_handle); </body> </html>