God of War: Ghost of Sparta "Restart from Checkpoint" loading speed regressions

[BonzaiThePenguin]

What happens?

After dying in God of War: Ghost of Sparta, the screen turns black and gameplay does not resume for 16 seconds.

What should happen?

The game displays "Loading" in the lower-right corner and restarts within 1-2 seconds.

What hardware and operating system are you running PPSSPP on? GPU might matter if it's a graphical issue.

Pixel 2, Android 8.1.

More information

Unfortunately the builds page is missing quite a few Android builds between the last known good version and the regression; this is as close as I was able to bisect it:

v1.5.4-198-gd487c7556 bad
v1.5.4-176-g43166c47e good

I'm curious if #10668 is directly related to this issue or a separate coincidental regression, as it too regressed at some point these two builds.

The latest build (v1.5.4-727-g9849ceadc) still exhibits both issues.

[unknownbrackets]

Based on that range, most likely candidates:

#10455 - I don't think this matters with map files off, though? In theory, it shouldn't be slower.
#10456 - This is probably the cause.

If it's not clearing or drawing, but flipping frequently and this is causing a slowdown, that seems like a different kind of bug than the FPS limiting was even meant to fix? Maybe it's causing sceDisplay timing to get confused and calculate timestep wrong?

-[Unknown]

[BonzaiThePenguin]

I can try to compile the project and narrow it down to the exact commit (it's almost certainly #10456 though), but if it's an acknowledged dirty heuristic would it be acceptable to just blacklist games that are known to interact poorly with the change and fall back to the old behavior?

[hrydgard]

I think we should simply whitelist that hack for the games it helps.

[unknownbrackets]

Whitelist the waiting on flip real PSPs don't do, or whitelist not waiting in games doing that breaks? Which is that hack?

-[Unknown]

[hrydgard]

Well, you got a good point there, it does probably make more sense the other way around.

[unknownbrackets]

I can't repro this in the demo, but #10785 may have helped if this had anything to do with frameskip.

Maybe we could do the same: if it did no drawing whatsoever, also delay? But that kinda seems weird, is it just because it uses flip immediate or something? Doesn't it mean we have a timing bug if - when it draws absolutely nothing - calling the flip function a lot makes the game slow?

-[Unknown]

[hrydgard]

I'm not sure, I'll see if I can figure something out.

[hrydgard]

Tested this, it's still an issue. It can be skipped easily using unthrottle though.

[hrydgard]

Something causes it to sleep, and it just idles (added some extra logging here):

39:23:741 idle0        I[SCEDISP]: hle\scedisplay.cpp:516 entering DoFrameTiming (throttle=1)
39:23:741 idle0        I[SCEDISP]: hle\scedisplay.cpp:574 DoFrameTiming: 0.030843
39:23:773 idle0        D[G3D]: thin3d\vulkanrendermanager.cpp:7 Vulkan: Acquired swapchain image 1
39:23:774 idle0        I[SCEDISP]: hle\scedisplay.cpp:688 __DisplayFlip
39:23:774 idle0        I[G3D]: hle\scedisplay.cpp:597 DoFrameIdleTiming
39:23:775 idle0        I[SCEDISP]: hle\scedisplay.cpp:688 __DisplayFlip
39:23:775 idle0        I[G3D]: hle\scedisplay.cpp:597 DoFrameIdleTiming
39:23:790 idle0        I[SCEDISP]: hle\scedisplay.cpp:688 __DisplayFlip
39:23:791 idle0        I[G3D]: hle\scedisplay.cpp:597 DoFrameIdleTiming
39:23:806 idle0        I[SCEDISP]: hle\scedisplay.cpp:688 __DisplayFlip
39:23:806 idle0        I[G3D]: hle\scedisplay.cpp:597 DoFrameIdleTiming
39:23:823 idle0        I[SCEDISP]: hle\scedisplay.cpp:688 __DisplayFlip
39:23:823 idle0        I[G3D]: hle\scedisplay.cpp:597 DoFrameIdleTiming
39:23:839 idle0        I[SCEDISP]: hle\scedisplay.cpp:688 __DisplayFlip
39:23:839 idle0        I[G3D]: hle\scedisplay.cpp:597 DoFrameIdleTiming
39:23:855 idle0        I[SCEDISP]: hle\scedisplay.cpp:688 __DisplayFlip
39:23:855 idle0        I[G3D]: hle\scedisplay.cpp:597 DoFrameIdleTiming
39:23:874 idle0        I[SCEDISP]: hle\scedisplay.cpp:688 __DisplayFlip
39:23:874 idle0        I[G3D]: hle\scedisplay.cpp:597 DoFrameIdleTiming
39:23:889 idle0        I[SCEDISP]: hle\scedisplay.cpp:688 __DisplayFlip
39:23:889 idle0        I[G3D]: hle\scedisplay.cpp:597 DoFrameIdleTiming
39:23:905 idle0        I[SCEDISP]: hle\scedisplay.cpp:688 __DisplayFlip
39:23:905 idle0        I[SCEDISP]: hle\scedisplay.cpp:725 No recent flip - displaying anyway.
39:23:905 idle0        D[FRAMEBUF]: common\framebuffercommon.cp Displaying FBO 0008c000
39:23:905 idle0        I[SCEDISP]: hle\scedisplay.cpp:516 entering DoFrameTiming (throttle=1)
39:23:905 idle0        I[SCEDISP]: hle\scedisplay.cpp:574 DoFrameTiming: 0.033456

[hrydgard]

Reverting this line "fixes" it though (as expected from the early results in this thread):

https://github.com/hrydgard/ppsspp/pull/10456/files#diff-4a63423fd3c6e0ac181a90222b514dd8R921

Not sure what the best fix might be...

[unknownbrackets]

Is it because cyclesAhead is small when gpuStats.numClears > 0 is false, and it end up recovering better?

What if gpuStats.numClears > 0 is around the entire thing (if (topaddr != 0 && topaddr etc.)? Does it still delay in other parts of the game correctly?

Seems like it must be that lastFlipsTooFrequent ends up behaving differently after that change.

-[Unknown]

[hrydgard]

Moving further investigation to 1.7.