Patapon 1 input lag (I want errrradicate it)

[LamerDrv]

(07-19-2016 08:01 AM)LunaMoo Wrote:  I can see this like that in Patapon third where it's very easy, but it doesn't really work in first one.

Perfect timing gives best drum sounds, so by hearing those means you have no problems pressing the buttons with perfect timing, I definitely heard those when making the cheat yesterday so I don't think messing with input timing is the right way to correct it, neither is my cheat which only works around the issue.

Each drum rewards certain amounts of points based on timing accuracy where max during fever is 1000 and starts from like 20% without any drum. Based on that I think our observed problem would happen when the function that checks the score runs before fourth drum score get's added, so you kind of making perfect input and can hear the results of it in-game, but it's not reflected in your score so you can never reach "early fever" and also once you get to the fever, it drops instantly, because score from just 3 drums most of the time doesn't pass requirements to keep the fever.

So most accurate approach would be finding a function which slowing down fixes the game, I'm thinking this could actually be similar to this issue, maybe it's even same thing which there potentially is caused by sceGeDrawSync running too fast. In Patapon 1 is called twice once every frame, so I think I'll experiment with slowing that a bit or anything else that happens before checking the score.

Hm.... stange....
A drum strike is evaluated by game as:
- "best" (ideal)
- "normal" (valid but not ideal)
- "wrong" (late or early).
(Of course they have a different sound)
On real psp I get 4 strikes in tact without problem.
But on ppsspp only half my strikes is best. And second half is "normal" (and occasionally is "wrong"). Like timing window for best strike was slightly shifted or ... I don't know.
(That is some strikes is still best. But 4 best strikes in tact is great rarity. In result I can't get early "fever".)
I seem that game evaluates all 4 strikes. But I can't make best 4 strikes.
That's why I insisted on timings.

(07-19-2016 08:01 AM)LunaMoo Wrote:  Edit: I think I was right on that:

Code:

_C0 Delay sceGeDrawSync
_L 0xE0085E3C 0x0001491C
//delay script
_L 0x20001F00 0x3C1B0880
_L 0x20001F04 0x3C090018
_L 0x20001F08 0x34080000
_L 0x20001F0C 0x1509FFFF
_L 0x20001F10 0x25080001
_L 0x20001F14 0x0A275E3C
_L 0x20001F18 0x00000000
//replace
_L 0x2001491C 0x0E2007C0
_C0 Delay sceGeDrawSync [Disable]
_L 0x2001491C 0x0E275E3C

with this, I can reach fever faster on clear game without using any other fever cheats I made earlier, it also allows me to keep it easier, althrough I think it also changes the timing for combos as well(no suprise if it breaks those since I delay it by loop with very high number of repeats choosen randomly without any research;p).

Sorry, I am a noob in "patchcrafting". Can you give a link to explain this syntax and soft for apply it?

[LunaMoo]

Read edits to my last post, I provided a build for testing:3 ~ unless you're not on windows, then would be cool if you can build ppsspp by yourself as I think I found a more proper fix that does not require patching the game and possibly would fix one other game as well.

Edit: As for syntax for cwcheats this site has some basic ones explained. There's probably not a single english site which has all of them explained, but frankly most are useless, I use primary 0xE and 0x2 type codes the first is just a basic 16 bit check and the other is 32 bit write. Good to also know that CWCheat address is just 28 bit and starts from PSP user memory, so 0 in cwcheat is basically 0x08800000 in disassembly.

If you ask how to activate cheats in ppsspp, first you activate them in system settings, then you'll see a new option on the pause screen called "cheats" inside will be a list of cheats you added to ini file that on desktop platforms can be opened from that menu directly, once everything is done and you have cheats in game ini file - ticking an entry on the list activates the cheat. It might be better explained in first post of this thread, althrough it's kind of outdated.

[LamerDrv]

I am on windows. I've try your test build. There is a difference... But ... it is hard to explain...
Usually on ppsspp I miss different strike on every tact. Sometimes I make 1th, 2th and 3th strikes ideal, 4th normal. Sometimes 2th - normal, 1th,3th,4th - ideal. I do not see clear patterns - as if mistakes are random.

But on your test build in first minute I can't take 4th strike ideal. Exactly 4th. Then I adapted, probably... And it have become as before ... with unclear subtle differences.
I'm starting to doubt myself.

Maybe there is a difference in settings of my ppsspp, which interacts with your modifications? (When I try run test build in empty folder it shows warning "Failed to load ui_atlas.zim. Place it in the directory "assets" under your PPSSPP directory." So I've I put it next to assests folder inside project folder. And it take my settings.)
Or maybe is it because I "Load state file"?

[LunaMoo]

Well that was just an exe with different name so placed in same directory as you have ppsspp would keep same settings, saves etc. savestates shouldn't really be used when testing, but I don't think it would affect this change much all it does is delay all functions which execute after the syscall that got slower.

I'm starting to doubt myself as well through;|, when I started testing this yesterday that was the first time I played any rhytm game on my crappy wireless keyboard so maybe I just sucked, weirdly after I tried the custom build maybe it had some placebo effect or something as now I'm able to reach early fever in unmodified ppsspp just as well pretty often I didn't changed any settings, didn't used cheats in neither version today I didn't used savestates either.

If you always fail at doing perfect 4th strike then the value of cycles eaten aka time spent on that syscall should be different, it really was taken out of the moon. I can't tell anymore the longer I test it, the less of a difference I see myself since the game becomes easier;|.

When you can't play by rhytm aka every strike varrying a bit, then it's possible it can be your settings, as lots of non default settings in ppsspp can affect timings, mostly breaking it, but we also have one option "force real clock sync" in system settings made specially for such games, recommend enabling it if you didn't yet.

[LamerDrv]

Hi, LunaMoo.
As I already said I'm not friends with assembler language .

Can you help with analyze (or maybe you already did it?):

I see the stack in moment when "fever mode" variable [09456694] is changed
z_un_0894b6e0 - there is places where fever mode=1 and fever mode=2
z_un_08951f20 - is called only if you make combo, there is place 08951FA4: numberOfCombo++
z_un_089511e8 - runs in cycle while you play level, but go past the first branch operator ONLY if you strike the drum
z_un_089510f0 - z_un_089510f0 - watch for drum buttons, runs in cycle after starting of level (don't runs while in Patapolis)
z_un_08950990
...

I have hopes for z_un_089511e8 ... but my knowledge is not enough for fast crack it

[LunaMoo]

Probably nobody can read it "fast" without getting confused, that's why you have to follow it instead of jumping in to potentially related places, if you still search for way to counter the delay you're having, following the variable that goes from 0 up to 2 might not be the best idea.

Better option would be to track down the variables that sets how well your timing was and since that feels kind of hard to find on it's own, start from something simpler like number of points per combo which in the end is saved in 0894B9C4 and trace back everything which add's to it. I belive the points for timing is actually read in 08879CF0, the other variables stored around those also look interesting. Either way tracing it back those "points" are saved in temporary space in 0894BD34 and are made by multiplying 100 by a fraction which changes depending on your timing. So now follow the fraction and can see if f12 is 0, we get perfect beat, tracting it even further back it goes through the function you found, but there's nothing useful happening there on it's own as that fraction is set earlier in 0887B188 which is something you should look at.
For example forcing the end result f0 to 0 in this function will pretty much freeze the white rectangle around the screen giving perfect results for every input:

Code:

_C0 Always perfect
_L 0xE001C440 0x0007B2EA
_L 0x2007B2E8 0x44800000
_C0 Always perfect [Disable]
_L 0x2007B2E8 0xC4400000

Which actually is a nice cheat on it's own, but if you want to just counter any delay you're having, you'll pretty much have to offset this value(still keeping it between 0 and 1) so the perfect aka 0 ends up at different frames, you could also offset it at different place ie affecting only the points or something else.

[LamerDrv]

Thank you very much!

[LamerDrv]

Hi.
Please, tell me how can I to "automate" testing the values in a place of a game code?

For example, I try to analyze z_un_0887b0a8 function of Patapon1 (one of function called from z_un_089510f0 which handling "drum keys"). I've "decompile" z_un_0887b0a8 to C language code and find input and output parameters (maybe ). In that case input parameters are [a0+0xC] and [a0+0x30], output parameters are [a1] and f0.
Now I would like to save the input and output parameters of this function in the emulator log. How can I do it?

[LamerDrv]

So I searched "timing" code starting from z_un_0894BBC8 pointed by LunaMoo.

I climbed up the call stack to z_un_089510f0.
Here is pseudocode of z_un_089510f0:

Code:

drum_key = check_drum_key(); //read data from keyboard handling routines (return values:-1 if no key tapped, 1-"circle"; 2-"cross"; 3-"square"; 4-"triangle")
....
f0 = z_un_0887b068(); //is this "timing"?
...
z_un_089511e8(drum_key, f0, ...); //inside: if (drum_key!=-1 then bunch of code including z_un_0894bbc8 call

z_un_0887b068 returns fixed values in a circle:
0,0 (mathes "ideal drum strike" )
0,133333
0,266667
0,400000
0,533333
0,666667
0,800000
0,933333
0,933333
0,800000
0,666667
0,533333
0,400000
0,266667
0,133333

As far as I understand z_un_089510f0 is called regularly. And for one "tact" z_un_089510f0 must be called 15 times.

May be so-called "input lag problem" is the result of non-constant frequency of calls of z_un_089510f0 in the emulator?
I tried to log the calls of z_un_089510f0 (I used the memory access breakpoint for this - is this right ?). According to the log file in most cases the time between calls is 30-35 msec. But sometimes the time between calls drops to 12 msec or rises to >100 msec.

It's intresting... is there possibility to measure the time between calls of z_un_089510f0 on PSP?

[LamerDrv]

A-a-a-a-a-a!!!!!!!!

Unknownbrackets, I see you commit 747a6e ("Debugger: Add custom log expressions"). Thanks!

[GamerzHell9137]

(08-07-2016 09:31 AM)LamerDrv Wrote:  A-a-a-a-a-a!!!!!!!!

Unknownbrackets, I see you commit 747a6e ("Debugger: Add custom log expressions"). Thanks!

What does that mean? The game won't have input lag?

[LamerDrv]

Unfortunately, not.

It means, that I have the opportunity for "profiling" game. I can save in log variables of the game (Of course, after finding these variables).
I set saving to log the variable that points the deviation of the drum strike from rhythm.
After several tests I got strange results - some of my missed drum strikes outrun the timings.
If would all my stikes late, I can "shift" timing constants. But if some strikes lag and some strikes outrun ... I don't know.

Now I try to understand the results of tests.

[LamerDrv]

It seems this is a dead end.
Can someone of the gurus tell what's next?

Here's what I managed to dig up so far:
LunaMoo found the point in code where drum strike is checked on ideality. Based on this I found the point in code where execution branches depending on whether the drum key is pressed.
Here's a rough pseudocode segment of the game that caught my attention:

Code:

get_drum_key();
get_current_timing();
...

if (key_is_pushed)
{
    huge chunk of code; //includes estimate using timing
}
else
    return;

This code is called with high frequency. Function get_current_timing() returns 15 different values in a circle:
0
0,133333
0,266667
0,400000
0,533333
0,666667
0,800000
0,933333
0,933333
0,800000
0,666667
0,533333
0,400000
0,266667
0,133333

Phone music tact in the game is 2 seconds - this is 4 background "boom" - once in 0.5 sec. That is the game divides the interval duration of 0.5 seconds to 15 segments. And for each segment the game checks if right key was pushed. If key was pushed and current timing is 0 - this is ideal strike.
If set loging point before "if" branching here is log:
22452 06:02:620 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f6eeeef
22640 06:02:636 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f6eeeef
22823 06:02:648 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f4ccccd
23001 06:02:662 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f2aaaaa
23188 06:02:677 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f088888
23376 06:02:716 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3ecccccc
23560 06:02:745 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3e888888
23743 06:02:781 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3e088888
23933 06:02:814 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=00000000 - moment for ideal strike
24161 06:02:846 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3e088889
24355 06:02:878 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3e888889
24538 06:02:912 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3ecccccd
24724 06:02:945 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f088889
24910 06:02:980 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f2aaaab
25092 06:03:011 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f4ccccd
25268 06:03:046 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f6eeeef
25489 06:03:078 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f6eeeef
25679 06:03:115 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f4ccccd
25866 06:03:145 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f2aaaaa
26054 06:03:178 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f088888
26240 06:03:213 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3ecccccc
26421 06:03:245 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3e888888
26598 06:03:279 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3e088888
26786 06:03:312 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=00000000 - moment for ideal strike
27085 06:03:348 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3e088889
27314 06:03:380 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3e888889
27505 06:03:415 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3ecccccd
27692 06:03:448 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f088889
27882 06:03:480 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f2aaaab
28072 06:03:513 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f4ccccd
28253 06:03:548 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f6eeeef
28478 06:03:579 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f6eeeef
28672 06:03:614 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f4ccccd
28867 06:03:646 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f2aaaaa
29049 06:03:680 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f088888
29274 06:03:712 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3ecccccc
29501 06:03:747 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3e888888
29703 06:03:781 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3e088888
29890 06:03:815 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=00000000 - moment for ideal strike
30227 06:03:849 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3e088889
30440 06:03:881 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3e888889
30646 06:03:916 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3ecccccd
30868 06:03:947 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f088889
31099 06:03:981 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f2aaaab
31305 06:04:017 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=3f4ccccd

s0=ffffffff=-1 means there is no pushed key - I didn't push any key.

Next, i set one more log point - inside ProcessKeyboard (in emluator code) and try to get the rhythm. I've attach the excerpt from log (with interpretation). In that log I can see that from my 32 drum strikes:
12 - ideal;
12 - too late;
8 - too early
It's stange. It's not like the problem with keyboard lag


One more experiment. Log point in game and grabbing sound by SoundForge (just phone sound, I didn't try to beat the drums).
See the jpg attachment.
   

This picture shows that there is little difference between execution speed of main thread and music the player hear. For example, time of background "boom" of 5th tact is 00:07,980. But time of call of get_current_timing() whit f0=0 in game is 00:08,012

I think that implementation of timing algorithm put strong requirement on speed of execution. And tiny speed deviations of main game thread and sound thread lead to the problem.

Maybe easier to patch the game than to improve emulator? For example get_current_timing() (z_un_0887b024) can be rewritten to return:
patched value | original value
0,933333 0,933333
0,800000 0,800000
0,666667 0,666667
0,533333 0,533333
0,400000 0,400000
0,266667 0,266667
0,000000 0,133333
0,000000 0,000000 --- expand time window for ideal moment
0,000000 0,133333
0,266667 0,266667
0,400000 0,400000
0,533333 0,533333
0,666667 0,666667
0,800000 0,800000
0,933333 0,933333

[[Unknown]]

23933 06:02:814 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=00000000 - moment for ideal strike
26786 06:03:312 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=00000000 - moment for ideal strike
29890 06:03:815 user_main N[JIT]: Debugger\Breakpoints.cpp:320 BKP PC=08951214: s0=ffffffff; f0=00000000 - moment for ideal strike

From my perspective, this timing looks very close - every 500ms with only slight inaccuracy (by +/- 3ms.) So the overall frequency is good and correct. However, looking at the windows:

06:02:781 BKP PC=08951214: s0=ffffffff; f0=3e088888 (33ms too early)
06:02:814 BKP PC=08951214: s0=ffffffff; f0=00000000 (32ms just right)
06:02:846 BKP PC=08951214: s0=ffffffff; f0=3e088889 (32ms too late)

06:03:279 BKP PC=08951214: s0=ffffffff; f0=3e088888 (33ms too early)
06:03:312 BKP PC=08951214: s0=ffffffff; f0=00000000 (36ms just right)
06:03:348 BKP PC=08951214: s0=ffffffff; f0=3e088889 (32ms too late)

06:03:781 BKP PC=08951214: s0=ffffffff; f0=3e088888 (34ms too early)
06:03:815 BKP PC=08951214: s0=ffffffff; f0=00000000 (34ms just right)
06:03:849 BKP PC=08951214: s0=ffffffff; f0=3e088889 (32ms too late)

It becomes more murky. The "just right" window varies by a few ms - as much as 10% of the target window. Unfortunately, operating systems like Windows make this hard to control - it could be that your antivirus or some updater got a couple ms of CPU time right then, or something.

I've seen PSP timing vary - but it's probably tighter. I'd guess it never varies more than 1ms away from the timing it's supposed to have.

That being said, timing some additional functions might definitely help - maybe the window is just slightly off (even if the interval and length is correct) because of the GPU timing. Ultimately, if that's true, you will NEED "real clock sync" to get stable timing in this game.

Just to clarify: with real clock sync off, time looks like this:

Code:

REAL WORLD  ||      GAME
            ||
1ms         ||       1ms
...         ||       5ms
5ms         ||      33ms (frame finished)
keypress    ||   (pause)
...         ||
33ms        ||  keypress

In other words, within a frame, 33ms in this case, the game "fast forwards" and finishes that frame as fast as possible. If this takes 5ms in the real world, then it just waits until the next frame before waking up. The game thinks time is moving normally, but we're just fooling it.

That means if you press a button at 6ms, it literally cannot be seen by the game until 33ms. In fact, if you pressed a button at 3ms, it might even see that as a button being pressed at 16ms. This is because time moves faster for the game - it's time traveling in small hops between frames.

Real clock sync changes this. It still HAS TO time travel, but with real clock sync, it only time travels between 2ms intervals or so. So with that option enabled, as long as the game is not running behind, a button press will never come in more than 2ms off. However, getting more accurate than that on Windows is problematic, because Windows doesn't do sub-millisecond timing. It just doesn't.

-[Unknown]