Grand Theft Auto Chinatown Wars (ULES01347):- Game crashes at the opening plane sequence since v0.9.1-842-g00f8ae5 (Atrac3+ issue)

[solarmystic]

Issue is as stated in the title.

First singular responsible build/commit found via bisecting is v0.9.1-833-gcf8a3e4 https://github.com/hrydgard/ppsspp/commit/cf8a3e4df1cb8f0b6cd1dec8c23952faf2cf19c9 which was merged into master with v0.9.1-842-g00f8ae5 https://github.com/hrydgard/ppsspp/commit/00f8ae5f2d07e8103c3e0eb838ae93762ce6dbdd https://github.com/hrydgard/ppsspp/pull/3772

Last unaffected revision is the one right before the commit was merged into master, v0.9.1-841-g26f935b https://github.com/hrydgard/ppsspp/commit/26f935bbe58d971831b88a97aec6d48995b65997

Problem reproduction:-

1. Download any 32 or 64 bit build from v0.9.1-842-g00f8ae onwards on the buildbot. (Self compilers can skip straight to the first responsible commit, v0.9.1-833-gcf8a3e4 by using the git reset --hard cf8a3e4df1cb8f0b6cd1dec8c23952faf2cf19c9 command). Make sure you've obtained the at3+ audio plugin and have it enabled in the Audio settings of the emulator.
2. Start a new game using default settings. If you have any previously created savedata for the game, move it elsewhere temporarily for the purposes of this reproduction.
3. During the opening white plane sequence that occurs right after the autosave screens, the game will crash, taking down the emulator with it and producing a Windows Error Report.

Windows Error Report:-

Problem signature:
  Problem Event Name:   APPCRASH
  Application Name: PPSSPPWindows64test0833unkat3.exe
  Application Version:  0.0.9.1
  Application Timestamp:    523737bd
  Fault Module Name:    at3plusdecoder64.dll
  Fault Module Version: 0.0.0.0
  Fault Module Timestamp:   51af42d5
  Exception Code:   c0000005
  Exception Offset: 000000000000191a
  OS Version:   6.1.7601.2.1.0.256.48
  Locale ID:    1033
  Additional Information 1: a32a
  Additional Information 2: a32a948565dd0feee1241d919b183e78
  Additional Information 3: d926
  Additional Information 4: d926d33c8a125bedaf5c40a6fc624afa

Stack Trace from affected 64bit debug build:-

Stack Trace from affected 32bit debug build:-

Logfile from an affected 64bit debug build until it crashes:- http://www.mediafire.com/download/9g0wbo629ngccuq/ppssppDebug64.7z

Logfile from an affected 32bit debug build until it crashes:- http://www.mediafire.com/download/623e117assjgycz/ppssppDebug32.7z

Temporary solution:-

Play through that entire section without the atrac3+ plugin enabled. Game will not crash if the plugin is either disabled or missing from your ppsspp directory. Game will lack BGM if you do that though.

[hrydgard]

I bet something causes it to try to decode invalid data as atrac3. The plugin is very intolerant to that unfortunately.

[unknownbrackets]

As far as I can tell from tests, this function basically asks the question, "where do I need to seek to in the file to start at this sample offset?"

The previous code said "the end." Always. Ys Seven got super confused by this answer, it's well above the range it expected to get. Now it returns the proper offset into the file where that sample starts. This number matches what the PSP outputs for the test files I tried.

I changed a few other things:

• If the entire file is already loaded into sceAtrac's memory, then the answer is always 0, which I implemented. Again, matches tests.
• If the sample offset is bogus (higher than the file's samples), an error code should be returned. Again, matches tests.
• If an invalid / unallocated atrac ID is passed, it shouldn't say "0" for everything, but instead return an error code without touching the memory. Again, matches tests.

It could be another syscall not handling errors properly, leading to bad data passed to this one or other ones in a way the game did not anticipate. Or, maybe for some types of atrac files these outputs are totally different (this is why I hate the atrac/mpeg/sas stuff.) I also noticed that the values of writeable bytes / min write bytes were wrong before (and they're still wrong.) Maybe with the correct file offset, games are now noticing this flaw.

Or it could even just be a bug in this atrac plugin thing.

-[Unknown]

[sum2012]

Does ppsspp have a check this as JPCSP ?

protected static final int atracIDMask = 0x000000FF;

public int checkAtracID(int atID) {
            atID &= atracIDMask;

            if (!atracIDs.containsKey(atID)) {
        log.warn(String.format("Unknown atracID=0x%X", atID));
        throw new SceKernelErrorException(SceKernelErrors.ERROR_ATRAC_BAD_ID);
    }

    return atID;
}

@HLEFunction(nid = 0xE23E3A35, version = 150, checkInsideInterrupt = true)
public int sceAtracGetNextDecodePosition(@CheckArgument("checkAtracID") int atID, TPointer32 posAddr) {

[unknownbrackets]

Definitely that mask business is not correct, per the audio/atrac/ids test there are a lot less and they are affected by sceAtracReinit().

sceAtracGetNextDecodePosition() does not return a proper error with a bad id.

-[Unknown]

[dbz400]

Humm GTA seems to be much more easier to reproduce .

[dbz400]

Alright .Everytime it crashed , sample is 0

[dbz400]

This is the log after i change this

    if ((u32)sample + atracSamplesPerFrame > (u32)atrac->endSample || sample == 0) {
        WARN_LOG(ME, "sceAtracGetBufferInfoForResetting(%i, %i, %08x): invalid sample position", atracID, sample, bufferInfoAddr);
        return ATRAC_ERROR_BAD_SAMPLE;
    }

36:30:069 idle0 I[SCEGE]: GLES\Framebuffer.cpp:1248 Decimating FBO for 04000000 (64 x 64 x 0), age 6 36:30:080 mix sound th I[ME]: HLE\sceAtrac.cpp:986 sceAtracReleaseAtracID(0) 36:30:089 mix sound th I[ME]: HLE\sceAtrac.cpp:1292 0=sceAtracSetHalfwayBufferAndGetID(08bfec80, 00001000, 00040000) 36:30:089 mix sound th W[ME]: HLE\sceAtrac.cpp:1173 This is an atrac3+ stereo audio 36:30:089 mix sound th W[ME]: HLE\sceAtrac.cpp:764 sceAtracGetBufferInfoForResetting(0, 0, 09fcf238): invalid sample position 36:30:090 mix sound th I[ME]: HLE\sceAtrac.cpp:992 sceAtracResetPlayPosition(0, 0, 0, 0) 36:30:090 mix sound th I[ME]: HLE\sceAtrac.cpp:1307 sceAtracSetLoopNum(0, -1) 36:30:128 threadmain I[SCEGE]: GLES\Framebuffer.cpp:603 Creating FBO for 04000000 : 64 x 64 x 0 36:30:131 threadmain I[SCEGE]: GLES\Framebuffer.cpp:603 Creating FBO for 04044000 : 64 x 64 x 0 36:42:145 idle0 I[SCEGE]: GLES\Framebuffer.cpp:1275 Destroying FBO for 00178000 : 480 x 272 x 3

[unknownbrackets]

What is Sampleoffset in that case?

I don't think 0 is an invalid sample offset at all. But maybe getDecodePosBySample() is giving an incorrect number for sample offset 0 in some files.

-[Unknown]

[dbz400]

Sampleoffset is 96

[unknownbrackets]

What happens if you force it to 0?

-[Unknown]

[dbz400]

int Sampleoffset = 0; ?

[unknownbrackets]

Yeah. Maybe when sample is 0, the offset should be 0 also.

-[Unknown]

[sum2012]

My Stack Trace is difficult

[dbz400]

Humm still crash

    if (sample == 0)
        Sampleoffset = 0;

[sum2012]

I have tried this code.But still crash in release mode.(debug mode no crash)

sceAtrac3plus.cpp bool Decode(Context context, void* inbuf, int inbytes, int outbytes, void outbuf) { ... void* buf;
__try { int ret = frame_decoder(context, inbuf, inbytes, &channels, &buf); if (ret != 0) { *outbytes = 0; return false; } } __except( EXCEPTION_EXECUTE_HANDLER ) { return false; }

[sum2012]

This is JPCSP trace log of this setting sceAtracGetNextDecodePosition 0xE23E3A35 2 https://gist.github.com/sum2012/e8634c5443f8b007ba92 Seem PSP do not return error in sceAtracGetNextDecodePosition

[unknownbrackets]

And sceAtracGetBufferInfoForResetting never returns an error either, right? (might need to trace sceAtracGetBufferInfoForReseting also.)

https://code.google.com/p/jpcsp/source/browse/trunk/src/jpcsp/HLE/modules150/sceAtrac3plus.java#556

JPCSP seems to put the same value in writable bytes as in min write bytes, which is definitely not what the PSP actually does. But it also seems to use the sample offset.

AFAICT JPCSP never returns an error either. Does this game work in JPCSP and play music fine? I realize it does not use the plugin thing.

Does it help to set atrac->currentSample = 0 or anything? Maybe it needs to reset the packets it's already sent to the decoder when this function is called, or somewhere else? Maybe it's crashing because of a mix of old packets + new packets after seeking?

-[Unknown]

[dbz400]

I will try this out shortly to set atrac->currentSample = 0

[sum2012]

Yes,sceAtracGetBufferInfoForReseting never returns an error in JPCSP trace log. https://gist.github.com/anonymous/3f0bc7c3ee5130c4ab05 edit:JPCSP play the music fine

[dbz400]

@unknownbrackets , tried atrac->currentSample = 0 or atrac->currentSample = sample , also crash .

[solarmystic]

This is related to the issue so I'll post it here instead of opening another redundant issue report page.

Apparently Grand Theft Auto: Vice City Stories (ULUS10160) also has the same exact issue as this game, with the same reponsible original commit https://github.com/hrydgard/ppsspp/commit/cf8a3e4df1cb8f0b6cd1dec8c23952faf2cf19c9

I discovered it purely by accident when testing the game for this particular @DanyalZia pull request https://github.com/hrydgard/ppsspp/pull/3822

Problem reproduction:-

Same as GTA Chinatown Stories, start a New Game with the atrac3+ codec enabled in any 32 or 64bit build from v0.9.1-842-g00f8ae5 onwards with default settings, skip through the opening cutscenes and the game will crash, taking down the emulator with it.

Disabling the atrac3+ plugin will mitigate the issue for now.

Stack Trace from 32bit debug build :-

Stack Trace from 64bit debug build :-

Logfile from an affected 64bit debug build:- http://www.mediafire.com/?w27q4xjn4i6nzdk

Logfile from an affected 32bit debug build:- http://www.mediafire.com/?dcvg710v3mxz9e1

[sum2012]

Stack Trace from from 32 bit (of Grand Theft Auto Chinatown Wars ) of at3plusdecoder.dll @raven02 Window 32 bit debug at3plusdecoder.dll you can test more to debug https://docs.google.com/file/d/0B3OaSdeV0L8kNnEwaldyQlFOODA/edit?usp=sharing

[dbz400]

I'm wondering if Memory::Write_U32(1, outposAddr); helps when invalid ID detected. (I cannot test it right now unfornaturely)

In sceAtracGetNextDecodePosition()

if (!atrac) {
        if (Memory::IsValidAddress(outposAddr))
            Memory::Write_U32(1, outposAddr);
     } else {

[sum2012]

@raven02 no help

[dbz400]

Ooops . Thanks for testing

[dbz400]

When crash , i got more detail on the values of Sampleoffset ,sample , minWritebytes

    int Sampleoffset = atrac->getDecodePosBySample(sample);
    int minWritebytes = std::max(Sampleoffset - (int)atrac->first.size, 0);
    INFO_LOG(HLE,"Sampleoffset = %i, sample = %i , minWritebytes = %i", Sampleoffset, sample, minWritebytes);

[dbz400]

14:40:130 I[HLE]: HLE\sceAtrac.cpp:770 Sampleoffset = 29743376, sample = 108776854 , minWritebytes = 29741328 14:40:181 I[HLE]: HLE\sceAtrac.cpp:770 Sampleoffset = 18855296, sample = 68957323 , minWritebytes = 18853248 14:53:949 I[HLE]: HLE\sceAtrac.cpp:770 Sampleoffset = 96, sample = 0 , minWritebytes = 0

[unknownbrackets]

Hmm, I think that value of minWritebytes is crazy.

What is atrac->first.writableBytes in this case?

I'm not really sure I understand these values, but it sounds like it's running against a very long atrac3+ file with a relatively small buffer, so that's probably what we should test against.

-[Unknown]

[dbz400]

This is the values before crash

33:32:950 mix sound th W[ME]: HLE\sceAtrac.cpp:1174 This is an atrac3+ stereo audio 33:32:950 mix sound th I[HLE]: HLE\sceAtrac.cpp:772 atrac->first.filesize = 845976 , atrac->first.size = 4096, atrac->atracBufSize = 262144, atrac->first.writableBytes = 262144

[dbz400]

I just tried to revert this line and seems to be it crashes on this line previously

from

          bufferInfo->first.filePos = atrac->first.fileoffset;

to

          bufferInfo->first.filePos = Sampleoffset;

[dbz400]

Therefore , we are passing 96 to bufferInfo->first.filePos now while previously we are passing 4096 to bufferInfo->first.filePos.

bufferInfo->first.filePos = atrac->first.fileoffset; INFO_LOG(HLE,"atrac->first.fileoffset = %i , Sampleoffset = %i", atrac->first.fileoffset , Sampleoffset);

     00:58:798 mix sound th I[HLE]: HLE\sceAtrac.cpp:786 atrac->first.fileoffset = 4096 , Sampleoffset = 96

[unknownbrackets]

Well, atrac->first.fileoffset is for sure wrong, at least in the common cases I tested. Just to clarify, are you saying that 4096 also crashes, or does not crash?

-[Unknown]

[dbz400]

4096 doeesn't crash . I also think bufferInfo->first.filePos = atrac->first.fileoffset; is wrong.

[solarmystic]

Apparently Class of Heroes also has the exact same issue, according to mr.chya from the ppsspp forums, which I verified by asking him to do some further testing.

http://forums.ppsspp.org/showthread.php?tid=419&pid=49712#pid49712

http://forums.ppsspp.org/showthread.php?tid=419&pid=49782#pid49782

Logfile courtesy of mr.chya from the forums:- http://forums.ppsspp.org/attachment.php?aid=8640

[dbz400]

For this issue .I'm wondering if we can use a workaround with comment here at least temporarily avoid this issue as there are few games already affected by this bug .

    // Workaround when sample <=0 for issue #3805
    if (sample <=0) {
        WARN_LOG(ME, "sceAtracGetBufferInfoForResetting(%i, %i, %08x): bad sample ", atracID, sample, bufferInfoAddr);
        return ATRAC_ERROR_BAD_SAMPLE;
    }

[unknownbrackets]

Wait, is sample negative? It's 0, right?

I expect other games to use sample=0 in very normal ways and probably wig out if it returns an error and fails to update the buffer properly.

-[Unknown]

[dbz400]

Should be 0 .I just put < in case there is sample indeed return negative though i'm not sure any games will do .

[unknownbrackets]

Well, for example in the audio/atrac/reseting test (which you can run in ppsspp without even a psp):

O 1: write=p+0x0, writable=00005a84, min=00000000, file=00000060 E 1: write=p+0x0, writable=00005998, min=000002f0, file=00000060

So, in that case, it's expecting minWriteBytes to be 0x2f0, and writable is off by a bit (too high by 0xEC.) I'm not sure why. But it does use 0x60 (96) for 0. What happens if you use minWriteBytes = 0x2f0? There's probably more to it, but I don't have the game to reproduce the crash...

-[Unknown]

[dbz400]

Humm do you mean simply change the following to see if it still crash ?

 int minWritebytes = std::max(Sampleoffset - (int)atrac->first.size, 0);

to

   int minWritebytes = 0x2f0;

[unknownbrackets]

Yes. Just want to see what variables might be involved.

-[Unknown]

[dbz400]

Alright .I will test it soon .

[dbz400]

I don't have the testing env this moment .However , if 0x2f0 didn't crash , that's mean Sampleoffset - (int)atrac->first.size return negtaive value then .

14:53:949 I[HLE]: HLE\sceAtrac.cpp:770 Sampleoffset = 96, sample = 0 , minWritebytes = 0

[dbz400]

0X2f0 is 752 . If (int)atrac->first.size = 848 then make sense (assume it is (int)atrac->first.size - Sampleoffset) = 848(atrac->first.size) - 96(SampleOffset) = 752(minWritebytes)

[dbz400]

Humm no luck .Tried minWritebytes = 0x2f0 , still crash

[sum2012]

@raven02 I try your hack code but don't work ?

      if (sample <=0) {
    WARN_LOG(ME, "sceAtracGetBufferInfoForResetting(%i, %i, %08x): bad sample ", atracID, sample, bufferInfoAddr);
    return ATRAC_ERROR_BAD_SAMPLE;

[dbz400]

Humm it should work .Let me try again .

[dbz400]

Just tried .It is okay and no crash.

[sum2012]

@raven02 Copy your code inside u32 sceAtracGetBufferInfoForResetting(int atracID, int sample, u32 bufferInfoAddr) ?

[dbz400]

Yes, right after

    if ((u32)sample + atracSamplesPerFrame > (u32)atrac->endSample) {
        WARN_LOG(ME, "sceAtracGetBufferInfoForResetting(%i, %i, %08x): invalid sample position", atracID, sample, bufferInfoAddr);
        return ATRAC_ERROR_BAD_SAMPLE;
    }

[sum2012]

Not sure don't work ... Maybe I am using Win32 build and you are using Win 64 build ?