Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

PulseAudio: Remove get_latency() caching #45152

Merged
merged 1 commit into from
Aug 4, 2023

Conversation

Birdulon
Copy link
Contributor

Removes the caching on AudioDriverPulseAudio::get_latency() and slightly renames variable name palat to pa_lat to slightly improve readability.

Rationale

As mentioned over at #38215 (comment) the API call pa_stream_get_latency returns different values at different times. Being able to sample it only once per program execution is a severe handicap when doing any profiling or using it for things such as latency compensation in rhythm games, as it can be wildly out if sampled under some load conditions.

As a somewhat hyperbolic analogy - what if you could only measure frame time once per program execution? What impact would that have on debugging and optimising your game?
Personally, I was about ready to tear apart my initialization routines when I noticed that my output latency number went from ~50ms to ~30ms on runs where I had breakpoints in initialization. Had I not investigated the engine source code I would have wasted considerable time chasing a dead end because of this cached value under the impression that Pulse was giving me conservative settings under certain start conditions!

Knock-on effects

Most of my testing has been on the 3.2 branch (Birdulon/godot/PAlatency) and all I've done on master is verify that it compiles and prints sensible values in a minimal project as I can't port my actual game to master due to unimplemented mesh rendering etc. (made this branch entirely because the default PR text told me to!)
In 3.2 I've observed no degraded performance with the Debugger's Monitors showing Audio Output Latency continuously during gameplay, however I noticed small bits of lag when I also had a label calling it 60 times a second in addition to the monitor. The documentation might need a small note to reflect that AudioServer.get_output_latency() and by extension Performance.get_monitor(Performance.AUDIO_OUTPUT_LATENCY) are potentially costly calls that should be used sparingly.
In master none of the performance monitors seem to draw for me, but I confirmed behavior with a label changing in _process.
I stress again that it should be preferable for this function to return what it says it does, even at cost, even if approximate, rather than lie to the programmer for the sake of saving cycles.

@Calinou Calinou added bug topic:audio cherrypick:3.x Considered for cherry-picking into a future 3.x release labels Jan 13, 2021
@Calinou Calinou added this to the 4.0 milestone Jan 13, 2021
@Calinou
Copy link
Member

Calinou commented Jan 13, 2021

The documentation might need a small note to reflect that AudioServer.get_output_latency() and by extension Performance.get_monitor(Performance.AUDIO_OUTPUT_LATENCY) are potentially costly calls that should be used sparingly.

Could you do that in this pull request (in the same commit)? See this page for instructions on updating the class reference.

@Birdulon Birdulon requested a review from a team as a code owner January 14, 2021 03:19
@Birdulon
Copy link
Contributor Author

Thanks for that, for some reason I'd assumed it would be a separate issue in the godot-docs repo! Added.

@akien-mga akien-mga requested review from a team January 26, 2021 14:26
@Birdulon
Copy link
Contributor Author

Birdulon commented Mar 1, 2021

Is there anything else that should be addressed?

@akien-mga
Copy link
Member

akien-mga commented Mar 1, 2021

Is there anything else that should be addressed?

The PR is fine but it needs to be reviewed by a contributor who knows about PulseAudio and/or general constraints on what can and can't be done in AudioDriver (likely @reduz for the latter).

Copy link
Contributor

@ellenhp ellenhp left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I like this change, but could we get some performance numbers? How long does this hold the global audio server lock for? Because people will 100% call this every frame and expect it to work. If it takes a millisecond or something I can live with that, but if it's holding the global audio server lock for 10 milliseconds that's not okay because it'll most likely cause buffer underruns.

Also do you have an idea of how much variation there is in the values returned by this function? If it's +/- 5% or something I'm not really convinced it's necessary to remove caching, but if there are latency spikes occasionally this might be a good change to merge.

@Birdulon
Copy link
Contributor Author

I like this change, but could we get some performance numbers? How long does this hold the global audio server lock for? Because people will 100% call this every frame and expect it to work. If it takes a millisecond or something I can live with that, but if it's holding the global audio server lock for 10 milliseconds that's not okay because it'll most likely cause buffer underruns.

I haven't run numbers on it, but I was able to play my rhythm game with the performance monitor charting it constantly on the 3.2 PR, without any noticeable audio issues.

Also do you have an idea of how much variation there is in the values returned by this function? If it's +/- 5% or something I'm not really convinced it's necessary to remove caching, but if there are latency spikes occasionally this might be a good change to merge.

As mentioned in the linked comment, it can be pretty severe. I've even seen it go over 100ms during initialisation, likely tied to whatever is happening on the frame it is called.
chart

@ellenhp
Copy link
Contributor

ellenhp commented Nov 26, 2021

I don't really think that ripple is worth tracking perfectly, especially because I suspect it's caused by the time to the next mix being different each time get_latency is called. That said, the spike there could cause serious problems. What if the value that we cache in the audio driver is way higher than the average latency because we got unlucky and cached an abnormally high value? We'd just have to wait until the game restarts I guess? Not good.

One thing I'd like to ask you to change is to continue caching the result of the call how we were before, but to clear the cache every time audio is mixed. That way we can continue to track the overall latency trend and give fresh data back, while providing an upper bound on the number of times we do this per frame. Latency isn't likely to change a huge amount between mixes, since unless I'm misunderstanding what it measures, it can't change any faster than time passes.

Also: Make sure to only ever read from or write to the cached value while the global audio server lock is held. We have enough intermittent threading issues as it is, I don't want to introduce more.

Thank you for looking into this by the way! The audio drivers are not my area of expertise so I appreciate people taking the time to contribute patches back to them.


edit: This has a double-benefit of giving rhythm game developers extremely fast tracking of latency information since they almost always turn the audio latency wayyy down, so the interval between audio mixes is extremely small. Let me know if you think it's a problem, but unless I'm missing something it seems like a nicer solution that completely eliminating latency caching.

@Crystalwarrior
Copy link

Any updates on this? We ran into this issue with just trying to replicate Ace Attorney blips which we expected to be extremely basic but is giving us hell. The reference video we're using for replicating that is https://www.youtube.com/watch?v=Min0hkwO43g
And in Godot the audio playback ended up being completely random and hard to figure out the culprit other than determining it must be audio buffer and inconsistent latency. We also encountered the issue of being unable to use the provided functions to introduce delay which further makes it impossible to develop any kind of sound-precision on even the basic audio presentation level.

@Calinou
Copy link
Member

Calinou commented Jan 1, 2023

@Crystalwarrior Please don't copy-paste comments across issues, as this makes the discussion more difficult to track for others.

I recommend testing this pull request locally and making it sure it actually fixes the issue for you.

@YuriSizov YuriSizov modified the milestones: 4.0, 4.1 Feb 16, 2023
@YuriSizov
Copy link
Contributor

YuriSizov commented Feb 16, 2023

Seems like this is generally positively received, so would be nice to finish it (rebase, review, approve) for 4.1 :)

@YuriSizov YuriSizov requested a review from a team February 16, 2023 12:12
@akien-mga akien-mga removed the cherrypick:3.x Considered for cherry-picking into a future 3.x release label Jun 19, 2023
@akien-mga akien-mga modified the milestones: 4.1, 4.2 Jun 19, 2023
@akien-mga akien-mga requested a review from ellenhp June 19, 2023 13:08
Copy link
Contributor

@ellenhp ellenhp left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code looks good and I do think this is a good idea because it gives users more flexibility to design their own latency compensation systems, which is something we don't currently support.

@ellenhp
Copy link
Contributor

ellenhp commented Jun 19, 2023

I will note that caching and clearing the cache every mix is still something that I think could be an improvement here because it would be nice if users could call this several times back-to-back without consequences, instead of having to call it once and cache it themselves. Not sure how beneficial that would be and it's a fair amount of extra work. It should be fine to ship this without that.

Copy link
Member

@akien-mga akien-mga left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks fine to me, but needs a rebase and a fix to the documentation.

@akien-mga
Copy link
Member

Sorry I should have mentioned this earlier too, could you squash the commits together? The doc change is directly required by the removal of caching so it makes sense to so both in the same commit.

@Birdulon
Copy link
Contributor Author

Birdulon commented Aug 4, 2023

Squashed

@Birdulon
Copy link
Contributor Author

Birdulon commented Aug 4, 2023

scons target=editor tests=yes dev_build=yes scu_build=yes precision=double use_asan=yes use_ubsan=yes linker=gold succeeded on my machine (linux x86-64), is there an intermittent build failure on CI?

@akien-mga
Copy link
Member

It fails after the build when running a test project. That's a known intermittent issue indeed. I restarted the CI job.

@akien-mga akien-mga changed the title PulseAudio: Remove get_latency() caching PulseAudio: Remove get_latency() caching Aug 4, 2023
@akien-mga akien-mga merged commit bf8069e into godotengine:master Aug 4, 2023
15 checks passed
@akien-mga
Copy link
Member

akien-mga commented Aug 4, 2023

Thanks! And apologizes for the huge delay reviewing and merging this. Thanks for sticking around :)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

6 participants