PCSX2 / pcsx2

PCSX2 - The Playstation 2 Emulator
https://pcsx2.net
GNU General Public License v3.0
11.63k stars 1.61k forks source link

Hot Shots Golf Fore!- MicroVU related stalling #1187

Closed MrCK1 closed 3 years ago

MrCK1 commented 8 years ago

Core issue:

Game is stuck on loading screen - related to DMAC apparently

-PCSX2 version: PCSX2 1.5.0-20160214222517

-PCSX2 options: Safest preset, native resolution (tested in OGL HW and SW) ) -Plugins used: OGL GSdx, SPU2-X, LilyPad, Linuz ISO/Gigaherz CDVD, the rest are null plugins

-Plugin settings: Defaults, no settings modifications affect the issue

-Description: After selecting "Go Play" the game will fail to progress past the loading screen.

-How to replicate: Select "Tournament" mode in main menu, select character, select "Go Play" and game will get stuck on loading screen.

-Last known version to work: 28 10 2013 1.1.0 r5754 (from PCSX2 wiki)

-PC specifications: CPU: Intel Core i5 4600 @ 3.2Ghz GPU: EVGA GTX750 SC 1GB OS: Windows 7 SP1 64-bit

Other comments: Starting in HW/SW mode and switching to the other did not help pass the loading screen either.

Oddly enough, it is a bit harder to reproduce this issue - sometimes the game loads without a problem. I can't seem to pinpoint what exactly is causing this. Messing with misc. speedhacks didn't seem to affect the loading error either.

IOP Interpreter/Preload TLB hack avoided the DMAC error but caused a reboot to BIOS

HW Mode Log: http://pastebin.com/unagm3tH SW Mode Log: http://pastebin.com/cMNgK8yF Stuck at Loading Screen

closeBinder()
openBinder("¥CRS¥GLY¥GLY0103.XB;1")
# TLB spad=0 kernel=1:12 default=13:30 extended=31:38
# Restart.
# Initialize GS ...
# Initialize INTC ...
# Initialize TIMER ...
# Initialize DMAC ...
# Initialize VU1 ...
# Initialize VIF1 ...
# Initialize GIF ...
# Initialize VU0 ...
# Initialize VIF0 ...
# Initialize IPU ...
# Initialize FPU ...
# Initialize User Memory ...
# Initialize Scratch Pad ...
# Restart Done.
# DMAC(5) Handler does not exist.
padman: DMA Busy ID = 207f0001 ret = 0
        SB_STAT = f0000102

With IOP Interpreter and Preload TLB Hack

closeBinder()
openBinder("¥CRS¥GLY¥GLY0118.XB;1")
# TLB spad=0 kernel=1:12 default=13:30 extended=31:38
# Restart.
# Initialize GS ...
# Initialize INTC ...
# Initialize TIMER ...
# Initialize DMAC ...
# Initialize VU1 ...
# Initialize VIF1 ...
# Initialize GIF ...
# Initialize VU0 ...
# Initialize VIF0 ...
# Initialize IPU ...
# Initialize FPU ...
# Initialize User Memory ...
# Initialize Scratch Pad ...
# Restart Done.
Get Reboot Request From EE
ROM directory not found

PlayStation 2 ======== Update rebooting..

PlayStation 2 ======== Update reboot complete
cdvdman Init
gregory38 commented 8 years ago

Preload tlb hack is designed to work with a single game. However you could use the EE interpreter to handle the tlb miss properly.

However it could be a timing issue.

refractionpcsx2 commented 8 years ago

Can you try the game with the EE Timing Fix and no Preload TLB hack and see what happens?

willkuer commented 8 years ago

After you tried what refraction suggested:

Can you as well validate that the mentioned version works for you?

The full list of svn revisions can be found here.

After you validated that it works please try to find the revision that broke using a binary (bisect) search method. You would probably need to look into these git revisions as well.

FlatOutPS2 commented 8 years ago

I tested the PAL demo of this game. Though I can't select Tournament mode, it loads fine any time.

MrCK1 commented 8 years ago

I did 2 "trials" with the EE Timing Fix. The 1st got stuck; and the 2nd shows the result when loaded successfully. I'll do more trials later. Apparently, the console is stalling before the Upper and Lower instructions can be called (more specifically bad code in microVU?)

Loading Stall

closeBinder()
openBinder("¥CRS¥GLY¥GLY0103.XB;1")
# TLB spad=0 kernel=1:12 default=13:30 extended=31:38
# Restart.
# Initialize GS ...
# Initialize INTC ...
# Initialize TIMER ...
# Initialize DMAC ...
# Initialize VU1 ...
# Initialize VIF1 ...
# Initialize GIF ...
# Initialize VU0 ...
# Initialize VIF0 ...
# Initialize IPU ...
IPU1 running when IPU1 DMA disabled! CHCR 1 QWC 0
# Initialize FPU ...
# Initialize User Memory ...
# Initialize Scratch Pad ...
# Restart Done.
# DMAC(5) Handler does not exist.
padman: DMA Busy ID = 1f2f0001 ret = 0
        SB_STAT = f0000102

Successful Load

openBinder("¥CRS¥SSN1¥BG010.XB;1")
closeBinder()
hole ------------------- 00000000 00000000
hole ------------------- 00d047d8 00d8b300
openBinder("¥CRS¥SSN1¥GRD0101.XB;1")
load hole start ----- mallinfo ------------------- 00d047d8 00d8b300
load hole end   ----- mallinfo ------------------- 00e78938 00efb300
closeBinder()
openBinder("¥CRS¥SSN1¥HOL0101.XB;1")
load ground start ----- mallinfo ------------------- 00e78938 00efb300
microVU0: Cached Prog = [001] [PC=0710] [List=01] (Cache=0.012%) [0.0mb]
Water Tris 16256
load ground end   ----- mallinfo ------------------- 00f39258 00f64300
microVU0: Cached Prog = [002] [PC=0570] [List=01] (Cache=0.016%) [0.0mb]
microVU0: FSSET Optimization
microVU0: FSSET Optimization
closeBinder()
openBinder("¥GE¥CUP¥CUP011.XB;1")
closeBinder()
microVU0: Cached Prog = [003] [PC=0178] [List=01] (Cache=0.019%) [0.0mb]
microVU0: Cached Prog = [004] [PC=0000] [List=01] (Cache=0.023%) [0.0mb]
openBinder("¥SND¥BGM¥C01_1_SQ.XB;1")
CollisionDatabase2 011f35f8 011f4300
closeBinder()
openBinder("¥GAME¥PVM.XB;1")
closeBinder()
microVU0: Cached Prog = [005] [PC=05d8] [List=01] (Cache=0.034%) [0.0mb]
microVU0: pState's cFlag Info was expected to be set [05d8]
microVU0: pState's cFlag Info was expected to be set [05e8]
microVU0: M-bit set! PC = 618
microVU0: M-bit set! PC = 620
microVU0: M-bit set! PC = 628
microVU0: M-bit set! PC = 630
microVU0: M-bit set! PC = 638
microVU0: M-bit set! PC = 640
microVU0: Cached Prog = [006] [PC=0668] [List=01] (Cache=0.039%) [0.0mb]
microVU1: Cached Prog = [056] [PC=3900] [List=02] (Cache=0.460%) [0.3mb]
microVU1: Cached Prog = [057] [PC=0020] [List=01] (Cache=0.573%) [0.3mb]
microVU1: Cached Prog = [058] [PC=12c8] [List=01] (Cache=0.574%) [0.3mb]
microVU1: Cached Prog = [059] [PC=12d8] [List=01] (Cache=0.574%) [0.3mb]
microVU1: Cached Prog = [060] [PC=35a8] [List=01] (Cache=0.574%) [0.3mb]
microVU1: Cached Prog = [061] [PC=12e8] [List=01] (Cache=0.574%) [0.3mb]
microVU1: Cached Prog = [062] [PC=1350] [List=01] (Cache=0.574%) [0.3mb]
microVU1: Cached Prog = [063] [PC=1368] [List=01] (Cache=0.574%) [0.3mb]
microVU1: Cached Prog = [064] [PC=1378] [List=01] (Cache=0.574%) [0.3mb]
microVU1: Cached Prog = [065] [PC=2868] [List=01] (Cache=0.604%) [0.4mb]
microVU1: Cached Prog = [066] [PC=28e8] [List=01] (Cache=0.604%) [0.4mb]
microVU1: Cached Prog = [067] [PC=25b0] [List=01] (Cache=0.604%) [0.4mb]
microVU1: Cached Prog = [068] [PC=25f8] [List=01] (Cache=0.604%) [0.4mb]
microVU1: Cached Prog = [069] [PC=2640] [List=01] (Cache=0.604%) [0.4mb]
microVU1: Cached Prog = [070] [PC=2688] [List=01] (Cache=0.604%) [0.4mb]
microVU1: Cached Prog = [071] [PC=26d0] [List=01] (Cache=0.604%) [0.4mb]
microVU1: Cached Prog = [072] [PC=2718] [List=01] (Cache=0.604%) [0.4mb]
microVU1: Cached Prog = [073] [PC=2b40] [List=01] (Cache=0.604%) [0.4mb]
microVU1: 1 cycle stall on branch instruction [2c68]
microVU1: 1 cycle stall on branch instruction [2c68]
microVU1: 1 cycle stall on branch instruction [2c68]
microVU1: 1 cycle stall on branch instruction [2c68]
microVU1: Branch Optimization
microVU1: Cached Prog = [074] [PC=2738] [List=01] (Cache=0.604%) [0.4mb]
microVU1: Cached Prog = [075] [PC=1b58] [List=01] (Cache=0.604%) [0.4mb]
microVU1: Cached Prog = [076] [PC=21a8] [List=01] (Cache=0.685%) [0.4mb]
microVU1: Cached Prog = [077] [PC=21c0] [List=01] (Cache=0.685%) [0.4mb]
microVU1: Cached Prog = [078] [PC=21d0] [List=01] (Cache=0.685%) [0.4mb]
microVU1: Cached Prog = [079] [PC=2230] [List=01] (Cache=0.685%) [0.4mb]
microVU1: Cached Prog = [080] [PC=2240] [List=01] (Cache=0.685%) [0.4mb]
microVU1: Cached Prog = [081] [PC=2250] [List=01] (Cache=0.685%) [0.4mb]
microVU1: Cached Prog = [082] [PC=2260] [List=01] (Cache=0.685%) [0.4mb]
microVU1: Cached Prog = [083] [PC=1d28] [List=01] (Cache=0.685%) [0.4mb]
microVU1: Cached Prog = [084] [PC=2278] [List=01] (Cache=0.685%) [0.4mb]
microVU1: Cached Prog = [085] [PC=2290] [List=01] (Cache=0.685%) [0.4mb]
microVU1: Cached Prog = [086] [PC=22a0] [List=01] (Cache=0.685%) [0.4mb]
microVU1: Cached Prog = [087] [PC=22b0] [List=01] (Cache=0.713%) [0.4mb]
microVU1: Cached Prog = [088] [PC=0540] [List=01] (Cache=0.713%) [0.4mb]
microVU1: Cached Prog = [089] [PC=0550] [List=01] (Cache=0.713%) [0.4mb]
microVU1: Cached Prog = [090] [PC=0560] [List=01] (Cache=0.713%) [0.4mb]
microVU1: Cached Prog = [091] [PC=0570] [List=01] (Cache=0.713%) [0.4mb]
microVU1: Cached Prog = [092] [PC=05f8] [List=01] (Cache=0.713%) [0.4mb]
microVU1: Cached Prog = [093] [PC=0608] [List=01] (Cache=0.713%) [0.4mb]
microVU1: Cached Prog = [094] [PC=0618] [List=01] (Cache=0.713%) [0.4mb]
microVU1: Cached Prog = [095] [PC=0628] [List=01] (Cache=0.713%) [0.4mb]
microVU1: Cached Prog = [096] [PC=0638] [List=01] (Cache=0.713%) [0.4mb]
microVU1: Branch Optimization
microVU1: Cached Prog = [097] [PC=07b8] [List=01] (Cache=0.713%) [0.4mb]
microVU1: Cached Prog = [098] [PC=0648] [List=01] (Cache=0.713%) [0.4mb]
microVU1: Cached Prog = [099] [PC=0658] [List=01] (Cache=0.713%) [0.4mb]
microVU1: Cached Prog = [100] [PC=0668] [List=01] (Cache=0.713%) [0.4mb]
microVU1: Cached Prog = [101] [PC=0678] [List=01] (Cache=0.713%) [0.4mb]
microVU1: Cached Prog = [102] [PC=0688] [List=01] (Cache=0.774%) [0.5mb]
microVU1: Cached Prog = [103] [PC=0428] [List=01] (Cache=0.774%) [0.5mb]
microVU1: Cached Prog = [104] [PC=0438] [List=01] (Cache=0.774%) [0.5mb]
microVU1: Cached Prog = [105] [PC=0448] [List=01] (Cache=0.774%) [0.5mb]
microVU1: Cached Prog = [106] [PC=0458] [List=01] (Cache=0.774%) [0.5mb]
microVU1: Cached Prog = [107] [PC=04b0] [List=01] (Cache=0.774%) [0.5mb]
microVU1: Cached Prog = [108] [PC=04c0] [List=01] (Cache=0.774%) [0.5mb]
microVU1: Branch Optimization
microVU1: Cached Prog = [109] [PC=04d0] [List=01] (Cache=0.774%) [0.5mb]
microVU1: Cached Prog = [110] [PC=04e0] [List=01] (Cache=0.797%) [0.5mb]
microVU1: Cached Prog = [111] [PC=2c88] [List=01] (Cache=0.798%) [0.5mb]
microVU1: Branch Optimization
microVU1: Cached Prog = [112] [PC=3358] [List=01] (Cache=0.803%) [0.5mb]
microVU1: Cached Prog = [113] [PC=3370] [List=01] (Cache=0.803%) [0.5mb]
microVU1: Cached Prog = [114] [PC=33a0] [List=01] (Cache=0.803%) [0.5mb]
microVU1: Cached Prog = [115] [PC=3470] [List=01] (Cache=0.803%) [0.5mb]
microVU1: Cached Prog = [116] [PC=3480] [List=01] (Cache=0.803%) [0.5mb]
microVU1: Cached Prog = [117] [PC=3900] [List=03] (Cache=0.803%) [0.5mb]
microVU1: Cached Prog = [118] [PC=3490] [List=01] (Cache=0.803%) [0.5mb]
microVU1: Cached Prog = [119] [PC=34a0] [List=01] (Cache=0.803%) [0.5mb]
microVU1: Cached Prog = [120] [PC=34b0] [List=01] (Cache=0.812%) [0.5mb]
microVU1: Cached Prog = [121] [PC=3900] [List=04] (Cache=0.812%) [0.5mb]
microVU1: Cached Prog = [122] [PC=3a98] [List=01] (Cache=0.815%) [0.5mb]
microVU1: Backing Up VF Reg [3c20]
microVU1: Backing Up VF Reg [3d08]
microVU1: Backing Up VF Reg [3d08]
microVU1: Backing Up VF Reg [3d08]
microVU1: Backing Up VF Reg [3d08]
microVU1: Backing Up VF Reg [3d08]
microVU1: Cached Prog = [123] [PC=34d0] [List=01] (Cache=0.855%) [0.5mb]
microVU1: Cached Prog = [124] [PC=34e0] [List=01] (Cache=0.855%) [0.5mb]
microVU1: Cached Prog = [125] [PC=3a10] [List=01] (Cache=0.855%) [0.5mb]
microVU1: Cached Prog = [126] [PC=34f0] [List=01] (Cache=0.855%) [0.5mb]
microVU1: Cached Prog = [127] [PC=3ad8] [List=01] (Cache=0.855%) [0.5mb]
microVU1: Cached Prog = [128] [PC=3500] [List=01] (Cache=0.855%) [0.5mb]
microVU1: Cached Prog = [129] [PC=3518] [List=01] (Cache=0.855%) [0.5mb]
microVU1: Cached Prog = [130] [PC=3530] [List=01] (Cache=0.855%) [0.5mb]
microVU1: Cached Prog = [131] [PC=3540] [List=01] (Cache=0.855%) [0.5mb]
microVU1: Cached Prog = [132] [PC=3550] [List=01] (Cache=0.880%) [0.5mb]
CollisionDatabase2  0.45s
CollisionDatabase2 maxList 3822
CollisionDatabase2 01421b08 0144d300
CollisionDatabase2 0022e510 00259000
CreateShadowMap  0.14s
microVU1: Cached Prog = [133] [PC=23b0] [List=01] (Cache=0.881%) [0.5mb]
microVU1: Cached Prog = [134] [PC=23c8] [List=01] (Cache=0.881%) [0.5mb]
microVU1: Cached Prog = [135] [PC=23d8] [List=01] (Cache=0.881%) [0.5mb]
microVU1: Cached Prog = [136] [PC=2428] [List=01] (Cache=0.881%) [0.5mb]
microVU1: Cached Prog = [137] [PC=2438] [List=01] (Cache=0.881%) [0.5mb]
microVU1: Cached Prog = [138] [PC=2448] [List=01] (Cache=0.881%) [0.5mb]
microVU1: Cached Prog = [139] [PC=2458] [List=01] (Cache=0.881%) [0.5mb]
microVU1: Cached Prog = [140] [PC=2468] [List=01] (Cache=0.881%) [0.5mb]
microVU1: Cached Prog = [141] [PC=2480] [List=01] (Cache=0.881%) [0.5mb]
microVU1: Cached Prog = [142] [PC=2490] [List=01] (Cache=0.881%) [0.5mb]
microVU1: Cached Prog = [143] [PC=3c68] [List=01] (Cache=0.897%) [0.5mb]
microVU1: 3 cycle stall on branch instruction [3f60]
microVU1: Cached Prog = [144] [PC=3c80] [List=01] (Cache=0.897%) [0.5mb]
microVU1: Cached Prog = [145] [PC=3c70] [List=01] (Cache=0.912%) [0.6mb]
microVU1: 3 cycle stall on branch instruction [3f60]
openBinder("¥SND¥BGM¥C01_1_BD.XB;1")
closeBinder()
ChangeSequence(1)
game standby ------------------- 00000000 00000000
game standby ------------------- 013635c8 0144d300
-2.161150
-2.887120 -5.048270
-3.347568 -8.395838
-4.380629 -12.776467
-5.415732 -18.192198
-6.927204 -25.119402
DropAngleXAverage:-4.186567
openBinder("¥CY¥SE0101.XB;1")
closeBinder()
openBinder("¥PC¥PC00¥PC00SW00.XB;1")
closeBinder()
change player  0.57s
MrCK1 commented 8 years ago

Tried SVN 5752, same result. - SVN notes states changes in that build were only related to openGL anyways

Maybe SuperVU was used during testing instead of MicroVU?

I tried SuperVU (on SVN and Git build) and the stalling never occured - even without the EE timing hack.

SuperVU didn't output these traces; so I assume they were added into MicroVU.

microVU0: FSSET Optimization
microVU0: pState's cFlag Info was expected to be set
microVU0: M-bit set! PC = 

@willkuer (I'm going all over the place) There was a discussion relating to another Hot Shots title that involved missing assets. The conclusion you drew at the time was related to the fact that PCSX2 didn't have a fully compatible FPU.

It seems like this is a specific issue with "Hot Shots" games (code isn't quite up to par yet?) as they rely heavily on micro mode (when VU0 acts as COP2) to stream data?

willkuer commented 8 years ago

Actually geoman was the one finding the solution. In your case it is emulation/game breaking in the other case it only glitches the graphics.

I would rather say the two cases are unrelated as they yield different problems and need different workarounds - but who knows. The game developer for sure seems to like using rarely used functions.

FlatOutPS2 commented 8 years ago

I finally got my hands on the full PAL version(Everybody's Golf) of this game last week and after several succesful loads I discovered it has the same issue. I managed to make a savestate early at the beginning of the loading screen that made the game stall every time. That meant I could do some decent testing and discovered that enabling the gamefix "FPU Negative Div Hack" made the game load from the savestate everytime. But once I did a few clean reboots without savestates the issue returned as usual. I remade the pre-stall savestate to be sure it wasn't a fluke, and the same thing happened, so with a few tweaks this fix might be able to resolve this issue or at least help towards a solution.

MrCK1 commented 8 years ago

This issue is still present in the latest git build. I'll continue to monitor it.

refractionpcsx2 commented 8 years ago

I still need to look in to this.

FlatOutPS2 commented 8 years ago

I remember catching the issue in savestate twice, one without "FPU Negative Div Hack" gamefix activated, and one with. Without the gamefix, turning it on gets by the error. With the gamefix activated, turning it off gets by the error. Doesn't help once the error has already been thrown though.

With "FPU Negative Div Hack" gamefix on the bug also seemed to take longer to appear, but only marginally so.

MrCK1 commented 8 years ago

I don't want to stray too far from the original problem, but something is keeping the GS at 90-100% usage "on the green" (5-6fps constant)

Setting changes seem to have no effect either :/

FlatOutPS2 commented 8 years ago

It even crashes in OpenGL hardware with 3x native now. This is a recent regression, looks like 1.5.0 dev 640 is the culprit(gsdx: increase the number of texture in the pool It could slightly increase the VRAM requirement but it will reduce texture allocation/unallocation at start/end of frame.).

gregory38 commented 8 years ago

@FlatOutPS2 Could you test with a limit of 30? https://github.com/PCSX2/pcsx2/commit/8ec146184276694c40710549c0cf0127c523414b#diff-08896891d15eba930b50d9710308324fR197

How much VRAM do you have?

FlatOutPS2 commented 8 years ago

Still crashes with limit set to 30. I have 2GB VRAM.

MrCK1 commented 8 years ago

Weird, crashing never occurred for me with 640 or any recent commits.
I'm not sure if I ever tested 3x native, but my VRAM usage is 800-900mb even at native res. I have 1GB VRAM

I noticed that there are alot of post-process transitions, (dissolves, wipes, ect) maybe this is causing a problem as well?

MrCK1 commented 7 years ago

Haven't encountered this at all in recent testing - the issue only occurs sometimes if the framerate is unclamped.

FlatOutPS2 commented 7 years ago

I can confirm it's gone in the PAL version too. It seems to have been fixed in a core commit from last September.

refractionpcsx2 commented 7 years ago

cool, ninja fix :P

FlatOutPS2 commented 7 years ago

I tracked it down to between builds 1237 (still active) and 1274 (gone). Most of the core fixes in that period are cleanups, so I'm not sure which build actually resolved it.

refractionpcsx2 commented 7 years ago

Strange, there isn't any mVU changes inside that range, maybe it wasn't mVU afterall.

MrCK1 commented 7 years ago

I thought it was EE core? Some games with this error still require the EE timing hack.

FlatOutPS2 commented 7 years ago

The only thing that changed anything relating to the issue AFAIK was the FPU Negative Div hack I mentioned earlier in the issue. I just checked and the only FPU change was just after it was already fixed. :P

FlatOutPS2 commented 6 years ago

Encountered this again today with latest build. First two attempts stalled.

MrCK1 commented 6 years ago

I wouldn't be surprised if the root of the issue is related to #2294.

MrCK1 commented 3 years ago

Should be fixed by this point, closing.

Unix0815 commented 6 months ago

The problem is still there with the newest nightly version. Sometimes the game loads just fine and sometimes it freezes at the loading screen.

Tested with pcsx2-v1.7.5645-windows-x64 and with both, the PAL and the NTSC-J release of the game.

refractionpcsx2 commented 6 months ago

Pretty sure the game has always done that.