RetroArch icon indicating copy to clipboard operation
RetroArch copied to clipboard

Automatic frame delay does not work correctly with Mupen64Plus and bsnes

Open nfp0 opened this issue 2 years ago • 5 comments

Description

Automatic frame delay does not adjust correctly with some cores, such as Mupen64Plus and bsnes. When enabled, and when "video_frame_delay" is set to a high enough value, the effective frame delay gets lowered below the target, but not enough to prevent the game from slowing down and prevent continuous audio crackling. The FPS value also goes down.

The games play at full speed and with perfect audio if frame delay is disabled or set lower, ruling out any lack of processing power.

Expected behavior

Automatic frame delay should kick in and lower the effective frame delay to a value that can sustain the game at full speed in all cases.

Actual behavior

Automatic frame delay kicks in, but does not lower the effective frame delay enough, resulting in audio crackling and game slowdown on some cores such as bsnes-mercury and Mupen64Plus-Next.

Steps to reproduce the bug

  1. Enable Automatic Frame Delay and set Frame Delay to a high value, such as 15.
  2. Open a heavy scene in a game, such as the first level of 007 Goldeneye or the initial cutscene in Pokemon Snap in Mupen64-Plus-Next set up with ParallelRSP and ParallelRDP. Alternatively, open the start screen of Yoshi's Island on bsnes-mercury.
  3. Observe game slowdown and audio crackling.

Version/Commit

  • RetroArch: 1.10.3

Environment information

  • OS: Manjaro Linux

nfp0 avatar Jul 22 '22 20:07 nfp0

@sonninnos

ghost avatar Jul 23 '22 08:07 ghost

I'm able to have some frame delay with Mupen64 with some games, but I need to have my GPU at maximum clocks, and one game (Conker) needs 3 swap chain images to keep up.

And heavy intro such as Doom 64 drops to 0 here pretty fast, but I'm running Windows. Yoshi also drops to non-crackling delay level quickly.

But sure something needs to be done since it is not supposed to get stuck in any case. I'd need some assistance though since I'm not able to run Vulkan in a VM, so can't take a closer look at the frame times. All I need is a log produced when FRAME_DELAY_AUTO_DEBUG is enabled in gfx/video_driver.c.

sonninnos avatar Jul 23 '22 11:07 sonninnos

@sonninnos I have confirmed that the games I've tested run at full speed with perfect audio when not using any frame delay. But these same games have slowdown and crackle when I enable Auto Frame Delay, which should not be possible. Auto Frame Delay is not doing it's job in this situation.

Also, I've tested with shaders enabled and disabled, and the situation is the same.

Can you not reproduce this issue on bsnes-mercury (balanced) on Yoshi's Island's title screen? It's pretty noticeable when enabling Auto Frame Delay and increasing Frame Delay to a big value, such as 15.

nfp0 avatar Jul 24 '22 15:07 nfp0

Like I said, it crackles for a while until it drops to a safe value.

sonninnos avatar Jul 24 '22 16:07 sonninnos

Not the case here. It never drops to a safe value. The crackling continues indefinitely. I can reproduce it easily every time. I have both my CPU and GPU at high-power profiles, btw.

nfp0 avatar Jul 24 '22 21:07 nfp0

Is it possible that you have some kind of adaptive vsync forced in the drivers? It did not occur to me since vulkan was involved, and since there is no adaptive vsync option in RA for it, but only for gl.

Having it enabled absolutely causes similar results. Also make sure video_refresh_rate is as close to display refresh rate as possible.

sonninnos avatar Nov 04 '22 19:11 sonninnos

@sonninnos The adaptive sync (G-Sync/Freesync) option on RetroArch is available for both GL and Vulkan. But no, I'm not using it. And video_refresh_rate is set correctly.

Regardless, I'll force-disable adaptive sync on the compositor (I'm using KDE), and see if I get different results.

nfp0 avatar Nov 04 '22 21:11 nfp0

VRR is not the same as Adaptive VSync, which only exists with gl and glcore in RA under Video > Synchronization.

sonninnos avatar Nov 04 '22 22:11 sonninnos

My bad. I thought you were talking about VESA's Adaptive-Sync. I believe Adaptive VSync is an Nvidia specific thing. I have an AMD card and I believe the equivalent is Enhanced Sync. Regardless, no, I'm not using either. I don't believe those driver settings are available on the Linux drivers, and if they are, I never enabled them.

nfp0 avatar Nov 04 '22 23:11 nfp0

@sonninnos Here's an example of the issue:

image

Auto-frame-delay lowered the frame-delay value to 12ms but it should go further down to achieve full speed. Notice that the framerate is stuck at 57 fps. This causes the game to run slower and with lots of audio crackling.

nfp0 avatar Nov 04 '22 23:11 nfp0

Ok, then I'm afraid I'm out of ideas what is making the calculation think the rate is solid.. That frame time and rate should absolutely be triggering the delay reduction.

So the only help would be seeing the log with that debug flag enabled.

sonninnos avatar Nov 05 '22 01:11 sonninnos

IMG_20221105_155801

@sonninnos Could it be related to this huge frame time deviation? (Sorry for the photo, but taking a printscreen ruins the frametime graph).

Notice how the max frametime is stuck at 26ms and the frame time deviation is 38%. A minimum frametime of 3ms also doesn't look normal. This is with all frame delay features disabled. Sometimes auto-frame-delay reduces it back to zero, which is kinda expected because 24ms is way higher than 16,6ms.

When that happens get this on the log:

[INFO] [Video]: Frame delay decrease by 1 ms to 14 ms due to frame time: 24999 > 16666.
[INFO] [Video]: Frame delay decrease by 1 ms to 13 ms due to frame time: 24999 > 16666.
[INFO] [Video]: Frame delay decrease by 1 ms to 12 ms due to frame time: 24999 > 16666.
[INFO] [Video]: Frame delay decrease by 1 ms to 11 ms due to frame time: 24999 > 16666.
[INFO] [Video]: Frame delay decrease by 1 ms to 10 ms due to frame time: 24999 > 16666.
[INFO] [Video]: Frame delay decrease by 1 ms to 9 ms due to frame time: 24999 > 16666.
[INFO] [Video]: Frame delay decrease by 1 ms to 8 ms due to frame time: 24999 > 16666.
[INFO] [Video]: Frame delay decrease by 1 ms to 7 ms due to frame time: 24999 > 16666.
[INFO] [Video]: Frame delay decrease by 1 ms to 6 ms due to frame time: 24999 > 16666.
[INFO] [Video]: Frame delay decrease by 1 ms to 5 ms due to frame time: 24999 > 16666.
[INFO] [Video]: Frame delay decrease by 1 ms to 4 ms due to frame time: 24999 > 16666.
[INFO] [Video]: Frame delay decrease by 1 ms to 3 ms due to frame time: 24999 > 16666.
[INFO] [Video]: Frame delay decrease by 1 ms to 2 ms due to frame time: 24999 > 16666.
[INFO] [Video]: Frame delay decrease by 1 ms to 1 ms due to frame time: 24999 > 16666.
[INFO] [Video]: Frame delay decrease by 1 ms to 0 ms due to frame time: 24999 > 16666.

Other times it just stays at a frame delay value not enough to reach full-speed, as seen on my post above here: https://github.com/libretro/RetroArch/issues/14201#issuecomment-1304332576

I've tested this on Mupen64Plus (with Parallel RDP and RSP), bsnes-mercury balanced, Mesen, and mGBA. This huge frame time deviation is present on all of them. What is causing this? Is this level of deviation normal on RetroArch?

nfp0 avatar Nov 05 '22 16:11 nfp0

That kind of deviation is absolutely not normal. I get a rock solid line with all drivers (vulkan/glcore/d3d11).

Still the delay should decrease when it is not solid, but I did have to add some exceptions for the way different drivers deal with frameskips, because the whole logic is based on frametime averages.. So you must be hitting some kind of sweet spot where the average seems not bad enough.

That basic log won't help, so please do try to compile RA with that debug flag enabled.

sonninnos avatar Nov 05 '22 17:11 sonninnos

Funny thing is the real-life frametime is perfectly smooth. There's absolutely no stutter. I can validate it by looking at the scroll test on the 240p test suite. I also recorded a 480fps (8 frames for each game frame) slow-motion video where you can see the perfect cadence of the frames on the clouds in the background despite the frametime deviation. Those numbers do not correlate at all with what I see on-screen.

https://user-images.githubusercontent.com/11202422/200138970-cd27bbb2-81f1-4868-bc54-3292bade2783.mp4

Tested it on both X and Wayland.

nfp0 avatar Nov 05 '22 20:11 nfp0

I get a rock solid line with all drivers (vulkan/glcore/d3d11)

Is that on Windows?

That basic log won't help, so please do try to compile RA with that debug flag enabled.

@sonninnos Aight, I'll do that as soon as I can.

nfp0 avatar Nov 05 '22 20:11 nfp0

Yes I'm using W10. I can't even get vulkan or glcore working in Linux VM, only gl.

sonninnos avatar Nov 05 '22 20:11 sonninnos

Oh, yeah, a VM will have all kinds of problems when it comes to running GPU programs.

So, has anyone tested this feature on Linux? Do you know anyone who has rock-solid frametime lines on Linux?

I believe the issue is that frame-time values might not be accurate. If you think about it, it's not possible to have frame-times of 20ms when all the frames are being delivered perfectly within the 16ms window, or is it?

nfp0 avatar Nov 05 '22 20:11 nfp0

No other actual Linux user has complained about it yet, and yes it has been tested on various hardware such as RPi.

And sure, there is no way for the average calculations to be reliable if the frame time values are not reliable. So fixing the frame time issue also fixes the autoframedelay issue. No idea where to start though.

Most likely something to do with GPU drivers and/or OS compositor.

sonninnos avatar Nov 05 '22 20:11 sonninnos

Most likely something to do with GPU drivers and/or OS compositor.

Quite probably, as I've noticed this "seesaw" frame-time pattern on other games too, even though they're visually smooth.

I would just set the frame delay manually, but using hardcore mode on Retroachievements forces me to have auto-frame-delay on. :disappointed:

I'll ask around on Discord or on the forums to see if other Linux users have this same issue.

nfp0 avatar Nov 05 '22 20:11 nfp0

Let's hope these new changes solve your problems too, since I discovered a few cases for myself that got the delay calculation stuck.

sonninnos avatar Dec 22 '22 17:12 sonninnos

Nice, I'll try it out when I get the chance. Thanks!

nfp0 avatar Dec 22 '22 19:12 nfp0

After updating to the latest version and after further testing I've found out that the irregular frametimes are much more severe on games that have high workload (such as the Yoshi's Island title screen and at the start of the GoldenEye's first level). Keep in mind that these games run at more than 200 fps when using fast-forward, so no performance issues here. The same games, on the same cores, have much lower frame time variance in areas of low workload.

The frametime variance can be as severe as oscillation between 2ms and 26ms which makes me wonder how can I get sound without any crackling when half the frames are clearly missing the 16,6ms window (60fps games).

I'm not sure if I should reopen this issue or create another more specific one. I would love to check with other Linux users if they have the same problem.

nfp0 avatar Mar 29 '23 19:03 nfp0

Something is seriously wrong with the presentation/buffering in your system then. I can't make more exceptions for the frame delay to drop in those cases, if it still won't, especially without the logs I wanted.

sonninnos avatar Mar 29 '23 19:03 sonninnos

Oh I'm sorry, I'm not asking for you to change the behavior anymore. I'm just trying to find the root cause of the problem on my end.

And I'm also sorry for completely forgetting to provide you the logs you asked with the debug flag. Here you go: retroarch.log

Find anything suspicious?

nfp0 avatar Mar 29 '23 20:03 nfp0

Nope, because that is just a normal debug log, and not the one with the frame delay debug flag:

All I need is a log produced when FRAME_DELAY_AUTO_DEBUG is enabled in gfx/video_driver.c.

sonninnos avatar Mar 29 '23 20:03 sonninnos

Oh my bad! I wasn't paying attention. Sorry for the trouble.

Here you go, with FRAME_DELAY_AUTO_DEBUG enabled: retroarch.log

I tested on bsnes mercury on Yoshi's Island start screen, where the frametime see-saws between 15 and 20 ms. Goldeneye is even worse.

nfp0 avatar Mar 29 '23 21:03 nfp0

Thanks. Looks pretty nasty, as in the average of every 8 frame block is over the available frame time, but it is not currently averaging the averages, so it stays within the allowed margin for normal spikes..

Not impossible take into account, but might be tricky to simulate without being able to replicate, while also not breaking everything else. I'll have to revisit it at some point.

Does it still stay put the same way if you start with some other more reasonable value like 10 or 8? And what about trying max swapchain 2, a different shader, or a smaller audio buffer?

sonninnos avatar Mar 29 '23 23:03 sonninnos

Thank you for looking into it. Not sure if you should change anything at all. My frametimes do not seem normal to me.

I just don't understand how can the game motion seem smooth when half the frames take 20 ms. Does this make sense?

Does it still stay put the same way if you start with some other more reasonable value like 10 or 8? And what about trying max swapchain 2, a different shader, or a smaller audio buffer?

Tried all of those but it made no difference. I even tried the null audio driver but the result was always the same seesaw frametime graph.

nfp0 avatar Mar 30 '23 00:03 nfp0

I think I now understand how it's possible for the picture to be perfectly smooth even with a seesaw frametime graph. On the default RetroArch syncronization method, the time distance between the current frame and the previous frame is irrelevant, as RetroArch holds on to the frame until the time is right to display it.

Still, it's weird that the frames are being rendered in such an erratic way. This is not a problem for the default RetroArch synchronization method, but when we enable VRR (Sync to exact content framerate), then the issue becomes apparent and we can see the frames being delivered irregularly. The smoothness is lost. And it also makes it difficult to use the awesome auto frame delay feature.

So I think I'll open a new separate issue and leave this one alone, as even though it affects the auto frame delay feature, it's unrelated to it.

Thank you for the help!

nfp0 avatar Mar 30 '23 16:03 nfp0

That kind of deviation is absolutely not normal. I get a rock solid line with all drivers (vulkan/glcore/d3d11).

@sonninnos Could you please specify your hardware a bit? I tested on Windows and I get about the same amount of frametime deviation than on Linux (about 14%). I also tested on a different computer and it also gives me about the same kind of deviation.

I can never get rock solid lines like you do. What software are you using to see the frametime graph?

nfp0 avatar Mar 30 '23 19:03 nfp0