Bust-A-Move Deluxe videos not working

[unknownbrackets]

Reported in #3338.

Details from @raven02:

video is not working and suppose to playback TAITO logo

the video stop with this error

58:25:385 user_main I[ME]: HLE\sceMpeg.cpp:368 sceMpegInit()
58:25:385 user_main I[ME]: HLE\sceMpeg.cpp:379 sceMpegRingbufferQueryMemSize(4800)
58:25:385 user_main I[ME]: HLE\sceMpeg.cpp:1132 sceMpegQueryMemSize()
58:25:385 user_main I[IO]: HLE\sceIo.cpp:842 stdout: Can't allocate memory for Mpeg Ring Buffer
58:25:385 user_main I[ME]: HLE\sceMpeg.cpp:1123 sceMpegFinish(...)

Details from @sum2012:

JPCSP trace log of Bust-A-Move(psp hang)
05:54:47 user_main - sceMpegRingbufferQueryMemSize 0x12C0 = 0x9D9E00
05:54:47 user_main - sceMpegQueryMemSize = 0xB3DB

PPSSPP Log:
https://gist.github.com/sum2012/c42b577c857a2f4b8283
08:36:140 user_main N[ME]: HLE\sceMpeg.cpp:377 10329600 = sceMpegRingbufferQueryMemSize(4800)
08:36:140 user_main N[ME]: HLE\sceMpeg.cpp:1130 65536 = sceMpegQueryMemSize()

Seem only sceMpegQueryMemSize result differcult

JPCSP no problem
log:
https://gist.github.com/sum2012/f3563ca747598605954c
Hmm

06:20:26 INFO hle.sceMpeg - user_main - sceMpegInit
06:20:26 DEBUG hle.sceMpeg - user_main - finishMpeg
06:20:26 DEBUG hle.sceMpeg - user_main - finishStreams
06:20:26 DEBUG hle.sceMpeg - user_main - sceMpegRingbufferQueryMemSize packets=0x12C0
06:20:26 DEBUG hle.sceMpeg - user_main - sceMpegQueryMemSize mode=0x0
06:20:26 DEBUG hle.sceMpeg - user_main - sceMpegRingbufferConstruct ringbufferAddr=0x088CF2C8, packets=0x12C0, data=0x0913FE80, size=0x9D9E00, callbackAddr=0x0885C800, callbackArgs=0x88CF28C
06:20:26 DEBUG hle.sceMpeg - user_main - sceMpegCreate mpeg=0x088CF2FC, data=0x09B19C90, size=0x10000, ringbufferAddr=0x088CF2C8, frameWidth=0x200, mode=0x0, ddrtop=0x0
06:20:26 DEBUG hle.sceMpeg - user_main - finishStreams
06:20:26 DEBUG hle.sceMpeg - user_main - sceMpegAvcDecodeMode mpeg=0x88CF2FC, modeAddr=0x088CF29C
06:20:26 DEBUG hle.sceMpeg - user_main - sceMpegQueryStreamOffset mpeg=0x88CF2FC, bufferAddr=0x09FFEDD0, offsetAddr=0x088CF304
06:20:26 INFO hle.scePsmf - user_main - Found PSMF MPEG video stream data: streamID=0xE0, privateStreamID=0x0, unk1=0x20, unk2=0xFB, EPMapOffset=0x0, EPMapEntriesNum=0, videoWidth=480, videoHeight=272
06:20:26 INFO hle.scePsmf - user_main - Found PSMF MPEG audio stream data: streamID=0xBD, privateStreamID=0x0, unk1=0x20, unk2=0x4, audioChannelConfig=2, audioSampleFrequency=2
06:20:26 INFO hle.sceMpeg - user_main - Using MPEG file for streaming: UmdIsoVirtualFile[UmdIsoFile(name='null', length=0x137800, startSector=0x81B0), sectorBlockMode=false]

-[Unknown]

Bust A Move Deluxe - USA 1.00

[sum2012]

Update the full debug log to v1.2.2-607-g21ba67e
https://drive.google.com/file/d/0B3OaSdeV0L8kN1FrNEotaFJVYlU/view?usp=sharing

[unknownbrackets]

sceKernelAllocPartitionMemory(partition = 2, UserSbrk, type= 3, size= 23068672, addr= 00001000)

Does Jpcsp also create a UserSbrk of this size? If so, it seems like the game can't allocate internally 10329600 bytes from this buffer (which is already almost all of RAM.)

Maybe this is a timing issue... maybe some internal thing hasn't freed whatever memory it's using yet?

-[Unknown]

[sum2012]

I add logging to check
21:15:29 ERROR hle.SysMemUserForUser - user_main - sceKernelAllocPartitionMemory partitionid, 2 name UserSbrk type 3 size 23068672 add 00001000)
21:15:29 ERROR hle.SysMemUserForUser - user_main - returning 18
seem allocate no problem

[sum2012]

@unknownbrackets
Yes,"Simuate umd delay" fix it.
full debug log: https://drive.google.com/file/d/0B3OaSdeV0L8ka2xNT1FfUUN0V1k/view?usp=sharing

[shinra358]

still an issue in 1.6

[unknownbrackets]

Yeah - especially if it traced sceIo functions. That said, it might alter their timing...

-[Unknown]

[unknownbrackets]

Ah, it's harder to tell without the log before/after each syscall. The version in my fork does that:
https://github.com/unknownbrackets/JpcspTrace

-[Unknown]

[unknownbrackets]

Based on that log, average timings:

Microseconds per byte:

• Average 1.3964
• Max 14.719
• Min 0.0718

Microseconds per sector assuming a full sector read:

• Average 0.6903
• Max 3.229
• Min 0.0718

And total overall timings (there's surely some factor of overhead):

• Average 4096
• Max 21415 (21ms)
• Min 869

Currently, our timing (which is based on memory stick access) is definitely much faster:

• 0.001us per byte
• +100000us (0.1s) if more than 204800 bytes distant from last read (interestingly this is higher than ANY max in that log)
• The 304 byte read (should be 869us) would've been 3us
• The 95533 byte read (should be 21415us) would've been 955us

I think it'd be worth trying just increasing the time for ISO by 20x, which might be more realistic. If you want to give this a shot, open Core/FileSystems/ISOFileSystem.cpp and find:

ppsspp/Core/FileSystems/ISOFileSystem.cpp

Lines 476 to 477 in bb5b981

	size_t ISOFileSystem::ReadFile(u32 handle, u8 *pointer, s64 size, int &usec) {
	EntryMap::iterator iter = entries.find(handle);

Add right below that:

	usec = size / 2 + 400;
	if (usec < 600) {
		usec = 600;
	}

That won't increase the read speeds for memory stick access, but it will increase it for all ISO/UMD access. But it might be that aligning to a sector is more realistic.

-[Unknown]

[sum2012]

Tested @unknownbrackets changed,no change
@benderscruffy the change build of win 64 bit

https://drive.google.com/file/d/1Duz2fiXM248Itc2hwqOSuMXQ0hMIYnqd/view?usp=sharing

[sum2012]

PPSSPP v1.10.3-1395-g1ba290a45 Windows 64 bit
still not working.
log: https://gist.github.com/sum2012/01fda17681bbc47bbcbdd5dbcf08c03d

Simuate umd delay log:
https://gist.github.com/sum2012/a650c52218cfffa5b876ed95849c9d57

[unknownbrackets]

Hm, the difference in those is:

48:42:185 ThreadFunc   I[SCEKERNEL]: hle\scekernelthread.cpp:2168 sceKernelExitThread(1)
48:45:637 user_main    E[SCEKERNEL]: hle\scekernelthread.cpp:2774 sceKernelSuspendThread(321): thread not running

It seems like ThreadFunc fails (exit 1 usually means an error) and then it can't be suspended.

Just to confirm, if you comment out this line:

ppsspp/Core/FileSystems/ISOFileSystem.cpp

Line 570 in 679a952

usec = 100000;

It makes "Simulate UMD Delays" not work, right? How low can you make 100000 and it still works? Does 10000 work?

-[Unknown]

[sum2012]

comment that line ,"Simulate UMD Delays" not work

My lowest value that work is 88463

It get a bluescreen in 87000

[ghost]

Add this game id to [ForceUMDDelay] fixes this issue.

[sum2012]

I think that we might be need to check the mpeg.prx crc

[hrydgard]

True, there might be multiple versions with different behaviors...

[sum2012]

I don't know that how to do crc of disc0:/PSP_GAME/USRDIR/module/mpeg.prx
old code uint32_t crcvalue = Reporting::RetrieveCRC(gamepath)
cannot do it.

[sum2012]

Anyway
update full debug of v1.13.1-653-g5200208a8 (bad)
and good ("Simulate UMD Delays" )
ppssppBADlog.zip
ppssppGOODlog.zip

[sum2012]

Update full debug log to v1.13.2-1304-g16f93a268
bad and good ("Simulate UMD Delays" )
ppsspp_bad_log.zip
ppssppgoodlog.zip

[sum2012]

v1.14.4-106-g765bfac01 still same.
Some info update,
18:12:998 user_main I[ME]: HLE\sceMpeg.cpp:462 sceMpegInit(), mpegLibVersion 0x104, mpegLibcrc 99de104f

[Sukotto-1999]

I found more info! Turns out this game seems to have anti-piracy measure a la Aces of War where it crashes when the Taito logo is about to play. It seems the game checks the loading time to ensure it's being run off the real UMD. This is ACTUALLY confirmed to happen on real hardware. I compressed the game to CSO via PSP CSO Compressor and then tested it on 6.61 LME-2.3 and then boom it works! (Sources: Adrenaline on ConsoleMods Wiki, GBATemp Forum) Maybe i should have a permanent fix; Force UMD delays for this game.

[sum2012]

@hrydgard Can add this game in ForceUMDDelay in compat.ini for v1.18 ?

[Panderner]

Please note: this game only occurs for US (Bust a Move Deluxe) & Europe (Bust-a Move Ghost) version of the game. Japanese version of the game (Ultra Puzzle Bobble Pocket) does not occur this bug.

[Panderner]

Only Japanese version of this game had a digital release.

[hrydgard]

Alright, I'll add it! Sorry @Sukotto-1999 , I missed your message somehow. Thanks for the reminder @sum2012