[jak2/3] Fix same-attack-invulnerable-timeout clock drift original game bug

[dallmeyer]

So target has some logic here which checks if the pending attack has the same ID as the last attack, and if so it checks for a 2s grace period (-> *TARGET-bank* same-attack-invulnerable-timeout) before the attack will actually count:

jak-project/goal_src/jak3/engine/target/target-util.gc

Lines 1664 to 1674 in 7320bfc

	(defbehavior target-log-attack target ((arg0 attack-info) (arg1 symbol))
	(if (and (= arg1 'background) (= (-> arg0 id) 2))
	(return #t)
	)
	(let ((a3-0 (the-as object (-> self attack-info-old))))
	(dotimes (a2-2 8)
	(let ((v1-9 (-> self attack-info-old a2-2)))
	(when (= (-> arg0 id) (-> v1-9 id))
	(if (not (time-elapsed? (-> v1-9 attack-time) (-> *TARGET-bank* same-attack-invulnerable-timeout)))
	(return #f)
	)

This same-attack-invulnerable-timeout check uses time-elapsed?, which under the hood references (current-time) AKA (-> PP clock frame-counter), which makes sense.

However the code that actually stores the attack-time uses a different clock (-> *display* base-clock frame-counter):

jak-project/goal_src/jak3/engine/target/target-util.gc

Lines 1765 to 1768 in 7320bfc

	(when (not (logtest? (-> this mask) (attack-mask attack-time)))
	(set! (-> this attack-time) (-> *display* base-clock frame-counter))
	(logior! (-> this mask) (attack-mask attack-time))
	)

So if these two clocks get out of sync - say the target process clock falls behind the *display* clock - then we can end up storing an attack-time that's "in the future" from target's perspective, effectively increasing the same-attack-invulnerable-timeout.

This clock drift can happen in real gameplay - Usual today was having it happen consistently with the route he was attempting for NoOOB. I was able to reproduce it consistently in OpenGOAL as well:

• get "invuln 2" (i.e. you have (target-flags disable-attacks) but not (focus-status dead ignore))
• restart mission at the top of temple before the glider mission trigger
• immediately go into the trigger and fall off the cliff (during the black screen)
• you'll get the glider cutscene, but should respawn back at the bottom of temple

Somewhere in this^ cutscene/blackout, the two clocks drift apart - presumably target's clock is paused but the other is not. Later in the speedrun, this causes the extra long invuln timeout bug, which wastes time while trying to intentionally lower health.

https://www.youtube.com/watch?v=WD2MLj8ccfg

As far as I can tell, any other code interacting with attack-time also uses (current-time) or one of the wrapping macros like set-time! or time-elapsed?

[dallmeyer]

some sample logs I added to show the clock drift before/after the glider cutscene

~~~~> 327745 *display* base-clock VS 327745 (current-time)
~~~~> 327750 *display* base-clock VS 327750 (current-time)
~~~~> 327755 *display* base-clock VS 327755 (current-time)
[23:01] [info] ISO thread: queueing VAG jakfall
[23:01] [info] IsoQueueVagStream allocating for jakfall 66614
[23:01] [debug] CDvdDriver swapping files MENU1   SBK - > VAGWAD  INT
[23:01] [debug] CDvdDriver jumping in file VAGWAD  INT: 0 -> 29261824
[23:01] [info] IsoPlayVagStream is unpausing jakfall
[23:03] [info] ISO thread: stopping jakfall since it is no longer requested
[23:03] [info] IsoStopVagStream is terminating jakfall (4)
---------> resetting with #<resetter-spec :continue "templex-after-intro" :reset-mode try :node none :execute #f @ #x2298b4>
[23:04] [info] VagUnPause (all of them)
[23:04] [info] VagUnPause (all of them)
ERROR: "temple-climb-res+0" could not find a master slot to link for #<art-joint-anim tpl-glider-temple-climb-res :length 13 @ #x97a94>.
ERROR: "temple-climb-res+0" could not find a master slot to link for #<art-joint-anim scenecamera-temple-climb-res :length 4 @ #x96074>.
ERROR: "temple-climb-res+0" could not find a master slot to link for #<art-joint-anim jakc-highres-temple-climb-res :length 59 @ #x8dd04>.
ERROR: "temple-climb-res+0" could not find a master slot to link for #<art-joint-anim daxter-highres-temple-climb-res :length 62 @ #x84174>.
[23:04] [info] STR_RPC for temple-climb-res chunk 1
[23:04] [debug] CDvdDriver jumping in file TECRES  STR: 135168 -> 90112
[23:04] [info] IsoPlayVagStream is unpausing temple-climb-res
Unload soundbank wasall1 from slot 0
Load soundbank hang1 in slot 0
[23:04] [debug] CDvdDriver swapping files WOMAP   STR - > HANG1   SBK
Unload soundbank temple1 from slot 2
hanga-activate
Load soundbank hang2 in slot 2
[23:04] [debug] CDvdDriver swapping files PRMINIMASTR - > HANG2   SBK
  level loading : want to unload hanga-vis. load-level is hanga-vis
Discarding level hanga
----------- deactivate(kill) #<level active hanga @ #x713c34> (status active)
hanga-deactivate
Adding level wasall
lev wasall 3 micro 0 tiny 0
Starting level load clock
Setting level templea display command to display
[23:04] [info] DGO RPC: new command ID, starting a load for wasall.DGO
Unload soundbank hang1 from slot 0
[23:04] [info] DGO RPC: CancelDGO NO CMD
[23:04] [info] Opening WASALL  DGO for DGO Load
[23:04] [debug] CDvdDriver swapping files TEMPLE6 SBK - > WASALL  DGO
Load soundbank wasall1 in slot 0
[23:05] [error] MIPS2C Function sparticle-motion-blur-dirt is registered multiple times, ignoring later registrations.
Elapsed time for level =       1.0666s
NOTICE: loaded wasall, 14928 bytes (14.5781 K) at top 1730288 at #x1d41b00 - #x1d45590
[23:05] [debug] CDvdDriver swapping files VAGWAD  ENG - > WASALL1 SBK
Displaying level wasall [special]
Done birth in -7420980
Unload soundbank hang2 from slot 2
Load soundbank temple1 in slot 2
[23:05] [debug] CDvdDriver swapping files VAGWAD  INT - > TEMPLE1 SBK
WARNING: enemy::move-to-ground: failed to locate ground for tomb-baby-spider-41!
WARNING: enemy::move-to-ground: failed to locate ground for tomb-baby-spider-42!
WARNING: enemy::move-to-ground: failed to locate ground for tomb-baby-spider-43!
WARNING: enemy::move-to-ground: failed to locate ground for tomb-baby-spider-44!
~~~~> 328750 *display* base-clock VS 328527 (current-time)
~~~~> 328755 *display* base-clock VS 328532 (current-time)
~~~~> 328760 *display* base-clock VS 328537 (current-time)

[ManDude]

Can you figure out which clocks are being used?

[dallmeyer]

Quick test in jak3:
#<clock @ #x72e454> (-> *display* base-clock) this is the one used for *default-pool*
#<clock @ #x72e5d4> (current-time) from *target* method
#<clock @ #x72e5d4> (-> *display* target-clock)

I'm not sure where the behavior differs between the two clocks during the temple example though. It looks like they've got the same mask (process-mask freeze pause menu progress):

gc> (-> *display* base-clock mask)
30        #x1e              0.0000        #<invalid object #x1e>

gc> (-> *display* target-clock mask)
30        #x1e              0.0000        #<invalid object #x1e>

So the only other thing I can think of is something changing one of the clock-ratios or time-adjust-ratios? Like you suggested, light jak freeze messes with this and can also cause the camera drift and invuln timeout bug:

~~>  342795 *display* base-clock  VS  341257 (current-time)
~~>  342800 *display* base-clock  VS  341262 (current-time)
~~>  342805 *display* base-clock  VS  341267 (current-time)
~~>  342810 *display* base-clock  VS  341272 (current-time)

[ManDude]

Looks like the resetter messes with the speed of the target clock.

[dallmeyer]

Looks like the resetter messes with the speed of the target clock.

oh yeah good find, if I duplicate all the (update-rates! (-> *display* target-clock) calls for base-clock in the resetter code then there's no clock drift introduced. Not sure that's a completely safe thing to change so I won't commit it, but good to know where it comes from.

[ManDude]

I think that's what makes Jak seem normal speed while a mission is restarting. Definitely don't touch that stuff.

I need to doublecheck if this is the correct clock to use in this attacking context, but I think it is.