AE: fix audio sync

[FernetMenta]

This is a concept fix for a major bug in AE. GetDelay returned random values because it did not consider context switches. In particular this was noticeable when transcoding was active. The audio error in dvdplayer was jumping back and forth by > 100ms.

I have done and tested this only for SoftAE yet but should be easy to add to the other engines too.
Thoughts?

[Albinoman887]

I will test right away. Can you give me a brief rundown o what softAE is/means? Does it just handle pcm or something

[Albinoman887]

Gave this a try. If I'm right and its for pcm (softAE) I for sure she a difference I think you got it! If so this is huge this bug as been plaguing me for about a year even before the AE merge. Amy plans up updating the rest of are?

[FernetMenta]

@Albinoman887
This is a dev space. You are welcome if you can contribute something to development otherwise please stay silent.
(SoftAE handles entire ALSA)

[Albinoman887]

I'm surprised how little attention this PR is getting its a major bug fix.

[MartijnKaijser]

@Albinoman887
If you have nothing constructive to say keep quit. you already have been warnd several times. this a dev area and not for users

[DDDamian]

@FernetMenta - excellent find. Not seeing fluctuations on win32 of more than ~+/-5ms but there have been repeated bug reports of discontinuities while transcoding to AC3 and I'd assumed without getting into it that there were buffering issues in the transcoding code.

Will test this asap - win32 and will force trancoding over HDMI - and comment.

[FernetMenta]

@DDDamian
I have update this. The lock can't be kept while writing to the sink. Needed an additional method for waiting until AddPackets won't block.

[DDDamian]

@FernetMenta - great - at first glance that was the only obvious issue was the lock. Pulling in now for a walkthru.

[Albinoman887]

Guys im not an idiot I have helped in development before I guess my my filter of what's OK to post here is skewed but I'm no idiot. I won't post again unless I have a log anymore

[amet]

@Albinoman887 problem is that when you say something, everyone even remotely associated with XBMC gets a email notification, use this place for constructive development discussion. stuff you consider a major bug might be the bug most of the people never experience.

[DDDamian]

@FernetMenta - I've played with this on win32 and not seen a difference in the stability of the sync error either trancoding or not. There is something very wrong in the trancoding code - among other things ffmpeg returns zero consistently in it's delay value referenced in AEEncoderFFmpeg::GetDelay() so we're getting some very bad fluctuations from that function, leading to the discontinuities when trancoding to AC3 when the total delay goes negative.

Digging into that issue. When not trancoding I get rock-solid numbers with or without these changes. When transcoding I get frequent glitches, so digging into that.

[FernetMenta]

I was thinking about maintaining a counter in the audio engine for the delay instead of accumulating delay over all buffers. When player adds a packet to the engine it increments the counter by the duration of the packet (observe resampling speed). Then transcoding can happen or not, when the audio engine puts the packet into the sink, the counter gets decremented.

GetDelay would return the counter + delay of the sink.

As far as I can see, currently resampling speed is not taken into account, right? At the beginning of the queue a packet might have a different duration than at the end.

[DDDamian]

That makes good logical sense. The resampler will change the number of samples but not the duration as the samplerate should always be factored in - this would be one downside of not tracking it per buffer. Resampling is the obvious case where a packet in / packet out counter would fail - a ratio would be required and could be messy

In the case of transcoding with ffmpeg not playing ball reporting its delay we may have to use an alternate arrangement such as simply calculating based on samples sent for transcoding, but I do need to dig deeper there.

The frequency of all these calcs (especially doubles) certainly adds processing overhead as they're performed every ~2ms or so by my tests.

[DDDamian]

Hmmm..repacking into MLP/MAT frames would be another case where packet-in/packet-out would be cumbersome.

[FernetMenta]

The resampler will change the number of samples but not the duration

I thought duration can change as a method of a/v sync. Wrong?

I am still measuring a variance of average audio sync error up to 20ms. Even with an increased interval of 2 secs for calculating the average error.

[Fneufneu]

CAESinkALSA::WaitReady is a c/c of the begin of CAESinkALSA::AddPackets ...

[DDDamian]

@FernetMenta - I have a fix for the transcoding issue. It is not currently addressed in this PR, but it fixes the variance you are seeing (specifically with transcoding).

Not sure if this PR further tightens sync - doesn't on my set-up as noted above, but I have no objections to this PR if you are seeing further improvement on your set-up. As noted the transcoding issue/fix is different to what this PR addresses.

[Albinoman887]

Do you have a PR for the transcoding issue? Or is it in your master branch
On Sep 24, 2012 3:43 PM, "Damian Huckle" notifications@github.com wrote:

@FernetMenta https://github.com/FernetMenta - I have a fix for the
transcoding issue. It is not currently addressed in this PR, but it fixes
the variance you are seeing (specifically with transcoding).

Not sure if this PR further tightens sync - doesn't on my set-up as noted
above, but I have no objections to this PR if you are seeing further
improvement on your set-up. As noted the transcoding issue/fix is different
to what this PR addresses.

—
Reply to this email directly or view it on GitHubhttps://github.com//pull/1422#issuecomment-8837802.

[DDDamian]

@Albinoman887 - neither, I'm just formatting it a bit for clarity and will post it in good time. It will be available once we determine if it supplements, replaces or is completely independent from this PR, which we are trying to discuss. Pushing it to master will conflict with this PR and vice-versa.

This is not a forum for requests etc. You have been asked by three team members to stop - make that four.

[Albinoman887]

I'm not requesting anything um trying to learn so I can be a dev one day
On Sep 24, 2012 8:24 PM, "Damian Huckle" notifications@github.com wrote:

@Albinoman887 https://github.com/Albinoman887 - neither, I'm just
formatting it a bit for clarity and will post it in good time. It will be
available once we determine if it supplements, replaces or is completely
independent from this PR, which we are trying to discuss. Pushing it to
master will conflict with this PR and vice-versa.

This is not a forum for requests etc. You have been asked by three team
members to stop - make that four.

—
Reply to this email directly or view it on GitHubhttps://github.com//pull/1422#issuecomment-8842424.

[FernetMenta]

@DDDamian - This PR fixes DTS-HD to AC-3 on my systems. (HDMI 2.0, only AC3 for pass through).
I noticed that I have missed the lock in transcoding stage.

I consider it as absolutely required to have those locks, otherwise GetDelay would always return incorrect values. Do you want me to try your fix on my systems?

[ghost]

@Albinoman887 shut up and observe or learn through other channels. this is the absolute final warning, and i mean it. i have a big fat boot and i will not hesitate a second before using it. if. a single new email with your interferences shows up you are out of here.

[DDDamian]

@FernetMenta - that would be great, especially as the scenario you describe would involve DTS>PCM>AC3 with transcoding. My fix at present does not include locking the transcoder stage but has a night-and-day effect. You'll laugh when you see the error. I'm at work right now but will push to my repo tonight with or without the transcoder locking (which should be added regardless, but you'll see the results as-is - will add locking if time allows tonight) and leave you a link here.

Cheers!

[DDDamian]

@FernetMenta - transcoding delay calcs fixed in DDDamian@55dd5db

Main issue found was that in SoftAE::GetDelay() we calculate the duration/delay of m_buffer based on an erroneous frame size - that of the encoded frames of 2ch * 2bytes = 4, when the actual buffer data may be 6ch * 4bytes = 24. This creates an artificial and much longer delay value than what is really stored, in turn leading to discontinuities when PTS/DTS values are calculated by DVDPlayerAudio.cpp.

In SoftAE.cpp lines 235-237 I store the framesize and sample rate of the pre-encoded PCM stream to use in the later calcs.

There are a few other math issues corrected which lead to bad calcs of the duration stored in the actual encoder buffer, but that's minor compared to the above.

Note that I have not added locking of the transcoder stage at this point.

Testing on a 5.1 AAC to 5.1 AC3 over HDMI the audio lag as reported in the OSD dropped from -0.020 - 0.100secs range to a nearly rock-steady 39ms +/- 2ms on my setup, which matches the non-transcoding values I typically see. So in terms of actual variance I'm seeing +/-2ms on a steady-state buffer duration of 39ms. The 39ms is the sum of the stream, engine, transcoder and sink buffers.

I was not able to test on a 2-ch TV - tests were done on Win 7 x64, quad-core AMD 1.8ghz, ATI 6450 to a Denon receiver over HDMI with transcoding forced by disabling AAC passthrough.

Locking the transcoder stage may improve this but I'm doubtful as the result is near identical now with straight passthrough, and the actual duration of the transcoder buffer is small compared to the stream and sink buffers.

All in all +/- 2ms is pretty good without more extensive locking which can actually hurt more than help.

This removes the extensive discontinuities or glitches when transcoding.

[FernetMenta]

@DDDamian
Great, seems to be almost fixed by your patch. I am still measuring a square-wave signal when looking at the audio sync error in DVDPlayerAudio. It has an amplitude of about 20ms. I don't think this is caused by the missing locks because it loos like a clean square-wave.
This causes skipped packets followed by duplicated ones.

Currently the average error is calculated every second. Increasing this time to 2 secs smooths the average error and all is fine.

Testing on Linux (ALSA) HDMI 2.0, only AC3 as pass through. Testmovie: TrueHD.

[DDDamian]

@FernetMenta - glad to hear it - thx for the fast testing! Just curious if you have any sync options enabled when you tested this or if you were going straight of audioclock without any sync/frequency modifying settings.

The second test would be whether our combined fixes further improves matters. Will try test both together tonight (if possible to reasonably merge).

[FernetMenta]

@DDDamian
I tested with "adjust refresh rate" and "sync playback to display". Video master, drop/dupe.

I think I found the reason for the square-wave: Dropped packets were added to the pts output and duplicated packets not. See: 038d1ff3c37b39a5a7fbf5287508bb9c3ca7c316

These 2 patches (038d1ff3c37b39a5a7fbf5287508bb9c3ca7c316 + DDDamian@55dd5db) fix the problem on my systems.

[elupus]

I wonder if moving m_ptsOutput into Dvdaudio.cpp would end up a smaller
diff. I've been wanting to do that for quite some time.

[FernetMenta]

@elupus
Makes sense to me. Would you do this change or do you want me to update this PR?

[elupus]

Give me until tomorrow. If I have not done anything tonight, it's probably
faster if you do it.

[elupus]

Okey.. soo: https://github.com/elupus/xbmc/compare/dvdaudio

But i'm not sure it solves the issue, since i couldn't really figure out what the result of the old code would be. My analysis tells me that the old code would do the following. First line being the packet entry with b duplicated 3 times:

a     b     b     b     e    
x  x' x' x' x' x' y  y' z  z' 

It so time would stop for a while between the end of the previous packet and the start of the last entered packet. New code does the following:

a     b     b     b     e    
x  x' y  y' y' y' y' y' z  z' 

Ie, time stops for a while after first packet has been entered. Without the last commit i did, it would be:

a     b     b     b     e    
x  x' y  y' y  y' y  y' z  z' 

With time jumping back for each added packet.

The new code you posted would do the following i think (xyzåäö is the normal order, ran out of letters).

a     b     b     b     e     f     g    
x  x' x' x' x' x' y  y' y  y' y  y' ä  ä'

Here weird things happen. First we stall clock, then clock keeps jumping back, then it skips several frames timestamps. But I can be fully wrong here, it's really hard to deduce :)

[DDDamian]

@FernetMenta - that explains a lot - my tests were done with no sync monkeying and I have nigh-perfect sync, and never drop/dupe as I use passthrough formats and am an audio nut lol.

Fix confirmed per http://forum.xbmc.org/showthread.php?tid=131237&pid=1200031#pid1200031

@elupus - you make my head explode ;)

Can I propose then:

• we do these fixes independently as they really are solving different issues
• I'll push the transcoder fix as it's a straightforward bug fix, elupus and FernetMenta agree to the skip/dupe fix and then we re-visit this PR?

[DDDamian]

@elupus - am I reading it wrong or in CDVDPlayerAudio::OutputPacket() does it not still add the packet when it is supposed to drop it? I see the duplicate, and the normal packet add, but in the skip condition it still writes the packet and just alters the m_skipdupcount?

I haven't followed further, just struck me as odd.

[FernetMenta]

It's more obvious when looking at the other end of the queue: CPTSOutputQueue::Current()

It pops of current entry if absolute time >= timestamp. Consider a case where a packet is duplicated a thousand times, this function returns pts of packet +1001. It should pop off an entry when absolute time passes front+1

  while( !m_queue.empty() && CDVDClock::GetAbsoluteClock() >= m_queue.front().timestamp )
  {
    m_current = m_queue.front();
    m_queue.pop();
  }

EDIT: disregard this post, too early in the morning.

[FernetMenta]

@elupus
I think your code is correct. I did not consider the case that pts would jump back because I tested with packets of 0.83ms duration.
The reason why I still see lots of drops/dupes is the size of the entire audio queue. GetDelay returns values around 1 sec. So if the interval of calculating the average error is 1 sec too, skip/dupe corrections are not considered for the next average error. Increasing the interval to 2 secs makes playback fine.

[elupus]

So I've rewritten the pts output queue to not depend on current time, only on current delay from audio output: https://github.com/elupus/xbmc/compare/dvdaudio

The feedback on re-added packets should now be immediate on current timestamp, which should be much
easier to calculate next add/drop values on. @FernetMenta Would be nice with some feedback how it works out, have not been able to test it properly myself.

[FernetMenta]

elupus, I have tested your new version. First I was looking only at skip/dupe messages in the log and noticed no difference to your last version.
But the a/v error on the codec screen is very jumpy with new changes. I would say it jumps between a range of 70ms, last two digits are not readable. (this test was done with AC3 pass through)
Without the last 2 commits the counter is very stable.

[elupus]

Ok, yea i wasn't entirely happy with how it turned out. But the principle
feels a lot better. It's not dependent on actual time. The first steps
there should not be worse than what we have. So we can get that in this
merge window.

[DDDamian]

Combine with elupus's work and rebase?

[FernetMenta]

I get best results with first 3 commits of https://github.com/elupus/xbmc/compare/dvdaudio and increasing interval for average error calculation (DVDPlayerAudio) from 1 sec to at least 2 seconds.

  //check if measured error for 2 second
  now = CurrentHostCounter();
  if ((now - m_errortime) >= m_freq * 2)

If elupus includes those lines in his change, this PR is obsolete.

[FernetMenta]

@elupus
In case you are busy and want me to pull your 3 commits into this pr, just let me know.

[elupus]

Feel free to pull those in here yes.

[FernetMenta]

updated and rebased. @elupus please hit the button if you are fine with it.

[FernetMenta]

@elupus
can we merge this?

[elupus]

Yes