avcodec_decode_audio4 in Grand Theft Auto: Chinatown Wars

[arqarq]

Game or games this happens in

ULUS-10490 - Grand Theft Auto: Chinatown Wars

What area of the game / PPSSPP

I am reporting an issue with GTA Chinatown Wars (CRC B9858E32) - the city ambient sound stops after about 25s (e.g., standing in the square in front of the hideout at the beginning of the game). It kills the immersion for me. Entering and exiting the car fixes the situation for the next 25 s. The log from the program is as follows:

10:24:649 Core\System.cpp:433 N[BOOT]: PPSSPP v1.17.1 Windows 64 bit
10:24:651 Core\Compatibility.cpp:151 N[G3D]: UnitsPerMeter for ULUS10490: 1.000000
10:25:889 root         N[BOOT]: UI\EmuScreen.cpp:389 Booted Grand Theft Auto Chinatown Wars.iso...
10:25:890 stupidthread E[SCEKERNEL]: HLE\sceKernelThread.cpp:2665 sceKernelWaitThreadEnd - bad thread 276
10:41:260 threadmain   E[SCEKERNEL]: HLE\sceKernelThread.cpp:2665 sceKernelWaitThreadEnd - bad thread 295
10:41:260 threadmain   E[SCEKERNEL]: HLE\sceKernelThread.cpp:2665 sceKernelWaitThreadEnd - bad thread 335
11:14:194 mix sound th E[ME]: HLE\sceAtrac.cpp:610 avcodec_decode_audio4: Error decoding audio -1094995529 / bebbb1b7
11:14:194 mix sound th E[ME]: HLE\sceAtrac.cpp:1566 UNIMPL sceAtracGetInternalErrorInfo(0, 09fee688)
15:56:710 mix sound th E[ME]: HLE\sceAtrac.cpp:610 avcodec_decode_audio4: Error decoding audio -1094995529 / bebbb1b7
15:56:710 mix sound th E[ME]: HLE\sceAtrac.cpp:1566 UNIMPL sceAtracGetInternalErrorInfo(0, 09fee688)
17:56:028 mix sound th E[ME]: HLE\sceAtrac.cpp:610 avcodec_decode_audio4: Error decoding audio -1094995529 / bebbb1b7
17:56:028 mix sound th E[ME]: HLE\sceAtrac.cpp:1566 UNIMPL sceAtracGetInternalErrorInfo(0, 09fee688)
29:57:316 mix sound th E[ME]: HLE\sceAtrac.cpp:610 avcodec_decode_audio4: Error decoding audio -1094995529 / bebbb1b7
29:57:316 mix sound th E[ME]: HLE\sceAtrac.cpp:1566 UNIMPL sceAtracGetInternalErrorInfo(0, 09fee688)

The radio music is okay. All audio options are set to default. I haven't checked those few builds after 1.17.1 because the buildbot is not working. In version 1.6.3 the duration of this sound is longer, but it still stops with the same error, eventually. Adding the game to [AtracLoopHack] option in 'compat.ini' completely ruins the music.

What should happen

Ambient sound should continue.

Logs

ppsspplog.zip

Platform

Windows

Mobile device model or graphics card (GPU)

NVIDIA GeForce RTX 3070

PPSSPP version affected

1.17.1

Last working version

tested as far as 1.6.3 - still N/G

Graphics backend (3D API)

Direct3D 11

Checklist

• Test in the latest git build in case it's already fixed.
• Search for other reports of the same issue.
• Try resetting settings or older versions and include if the issue is related.
• Try without any cheats and without loading any save states.
• Include logs or screenshots of issue.

[anr2me]

I wondered whether this PR can fix this issue or not.
Unfortunately, the artifacts have expired.

[sum2012]

v1.17.1-16-gf5450e40e full log: https://gist.github.com/sum2012/2f1c2ce8595b04452f56cfd7b289ffcc

@anr2me
The remain frame is -1 before so that it is not apply #18396
:54:002 mix sound th D[ME]: HLE\sceAtrac.cpp:1395 00000000=sceAtracDecodeData(0, 08d60eb8, 08b5c2f4[00000800], 08b5c2e0[00000000], 08b5c2d4[-1])
55:54:068 mix sound th D[ME]: HLE\sceAtrac.cpp:1667 0=sceAtracGetRemainFrame(0, 09fee660[ffffffff])
55:54:068 mix sound th D[ME]: HLE\sceAtrac.cpp:1596 sceAtracGetNextDecodePosition(0, 09fee680)
55:54:068 mix sound th D[ME]: HLE\sceAtrac.cpp:1643 sceAtracGetNextSample(0, 09fee684): 2048 samples left
55:54:068 mix sound th D[ME]: HLE\sceAtrac.cpp:1395 00000000=sceAtracDecodeData(0, 08d5ceb8, 08b5c2f4[00000800], 08b5c2e0[00000000], 08b5c2d4[-1])
55:54:102 mix sound th D[ME]: HLE\sceAtrac.cpp:1667 0=sceAtracGetRemainFrame(0, 09fee660[ffffffff])
55:54:102 mix sound th D[ME]: HLE\sceAtrac.cpp:1596 sceAtracGetNextDecodePosition(0, 09fee680)
55:54:102 mix sound th D[ME]: HLE\sceAtrac.cpp:1643 sceAtracGetNextSample(0, 09fee684): 2048 samples left
55:54:102 mix sound th I[ME]: HW\MediaEngine.cpp:103 FF: Frame data doesn't match channel configuration!
55:54:102 mix sound th E[ME]: HLE\sceAtrac.cpp:607 avcodec_decode_audio4: Error decoding audio -1094995529 / bebbb1b7
55:54:102 mix sound th D[ME]: HLE\sceAtrac.cpp:1395 80630024=sceAtracDecodeData(0, 08d5eeb8, 08b5c2f4[00000000], 08b5c2e0[00000001], 08b5c2d4[0])
55:54:102 mix sound th E[ME]: HLE\sceAtrac.cpp:1563 UNIMPL sceAtracGetInternalErrorInfo(0, 09fee688)

[arqarq]

The error in full log is different in this case.
File plays just fine in ffplay.

[sum2012]

@arqarq I have switched the Media log level to debug

=============
seem revert #18414 + apply #18396 fix the issue

[anr2me]

seem revert #18414 + apply #18396 fix the issue

Does doing this also fixes games that were fixed by #18414 ?

[sum2012]

seem revert #18414 + apply #18396 fix the issue

Does doing this also fixes games that were fixed by #18414 ?

No

[arqarq]

Thanks, it works indeed! Will this be in the official version?

[sum2012]

Need more testing

[arqarq]

Ok, so I'm happy to play around with git from now on, especially when buildbot isn't working.

[arqarq]

Unfortunately, it still occurs (own build with -#18414 / +#18396).

05:16:905 threadmain   D[SCEKERNEL]: HLE\sceKernelSemaphore.cpp:293 sceKernelSignalSema(299, 1) (count: 0 -> 1)
05:16:905 threadmain   D[SCEKERNEL]: HLE\sceKernelTime.cpp:132 sceKernelSysClock2USecWide(clock = 120269795, lo = 09ffea80, hi = 09ffea84)
05:16:906 threadmain   D[SCEKERNEL]: HLE\sceKernelTime.cpp:132 sceKernelSysClock2USecWide(clock = 120270220, lo = 09fff590, hi = 09fff594)
05:16:906 threadmain   D[SCEKERNEL]: HLE\sceKernelTime.cpp:132 sceKernelSysClock2USecWide(clock = 120270224, lo = 09fff580, hi = 09fff584)
05:16:906 threadmain   D[SCEKERNEL]: HLE\sceKernelSemaphore.cpp:401 0=sceKernelWaitSema(287, 1, 167769408)
05:16:906 idle0        D[SCEKERNEL]: HLE\sceKernelThread.cpp:3087 Context switch: threadmain -> idle0 (279->272, pc: 08a75500->08000000, sema waited) +802us
05:16:906 mix sound th D[SCEKERNEL]: HLE\sceKernelThread.cpp:3087 Context switch: idle0 -> mix sound thread (272->340, pc: 08000000->08a6da94, woke from hle delay) +1009us
05:16:906 mix sound th D[SCEKERNEL]: HLE\sceKernelEventFlag.cpp:513 0=sceKernelPollEventFlag(336, ffffffff, 00000001, 08b5c2cc[00000028])
05:16:906 mix sound th D[ME]: HLE\sceAtrac.cpp:1666 0=sceAtracGetRemainFrame(0, 09fee660[000000d9])
05:16:906 mix sound th D[ME]: HLE\sceAtrac.cpp:1598 sceAtracGetNextDecodePosition(0, 09fee680)
05:16:906 mix sound th D[ME]: HLE\sceAtrac.cpp:1642 sceAtracGetNextSample(0, 09fee684): 2048 samples left
05:16:906 mix sound th I[ME]: HW\MediaEngine.cpp:103 FF: Frame data doesn't match channel configuration!
05:16:906 mix sound th E[ME]: HLE\sceAtrac.cpp:607 avcodec_decode_audio4: Error decoding audio -1094995529 / bebbb1b7
05:16:906 mix sound th D[ME]: HLE\sceAtrac.cpp:1398 80630024=sceAtracDecodeData(0, 08d5e2cc, 08b5c2f4[00000000], 08b5c2e0[00000001], 08b5c2d4[0])
05:16:906 mix sound th D[HLE]: HLE\HLE.cpp:694 Compiling syscall to sceAtracGetInternalErrorInfo
05:16:906 mix sound th E[ME]: HLE\sceAtrac.cpp:1565 UNIMPL sceAtracGetInternalErrorInfo(0, 09fee688)
05:16:906 mix sound th D[SCEKERNEL]: HLE\sceKernelEventFlag.cpp:312 0=sceKernelSetEventFlag(336, 00000004)
05:16:906 mix sound th D[SCEKERNEL]: HLE\sceKernelEventFlag.cpp:271 0=sceKernelClearEventFlag(336, ffffffdf)
05:16:906 mix sound th D[SCEKERNEL]: HLE\sceKernelEventFlag.cpp:312 0=sceKernelSetEventFlag(336, 00000004)
05:16:906 mix sound th D[SCEKERNEL]: HLE\sceKernelEventFlag.cpp:513 0=sceKernelPollEventFlag(336, ffffffff, 00000001, 08b5c2cc[0000000c])
05:16:906 mix sound th D[ME]: HLE\sceAtrac.cpp:1666 0=sceAtracGetRemainFrame(0, 09fee660[000000d9])
05:16:906 mix sound th D[SCEKERNEL]: HLE\sceKernelEventFlag.cpp:271 0=sceKernelClearEventFlag(336, ffffffdf)
05:16:906 mix sound th D[SCEIO]: HLE\sceIo.cpp:2175 0=sceIoCloseAsync(9)
05:16:906 mix sound th D[SCEKERNEL]: HLE\sceKernelEventFlag.cpp:513 0=sceKernelPollEventFlag(336, ffffffff, 00000001, 08b5c2cc[0000000c])
05:16:906 mix sound th D[SCEKERNEL]: HLE\sceKernelSemaphore.cpp:401 0=sceKernelWaitSema(337, 1, 0)
05:16:906 SceIoAsync   D[SCEKERNEL]: HLE\sceKernelThread.cpp:3087 Context switch: mix sound thread -> SceIoAsync (340->360, pc: 08b1824c->08220e00, sas core) +24us
05:16:906 SceIoAsync   D[SCEIO]: HLE\sceIo.cpp:2956 ASYNC 0 = sceIoCloseAsync(9)

[arqarq]

Something new in the log:

46:59:591 mix sound th D[SCEKERNEL]: HLE\sceKernelThread.cpp:3087 Context switch: idle0 -> mix sound thread (272->340, pc: 08000000->08a6d92c, audio drain) +4673us
46:59:591 mix sound th D[SCEKERNEL]: HLE\sceKernelEventFlag.cpp:513 0=sceKernelPollEventFlag(336, ffffffff, 00000001, 08b5c2cc[00000028])
46:59:591 mix sound th D[ME]: HLE\sceAtrac.cpp:1666 0=sceAtracGetRemainFrame(0, 09fee660[000000af])
46:59:591 mix sound th D[SCEKERNEL]: HLE\sceKernelSemaphore.cpp:401 0=sceKernelWaitSema(299, 1, 167699984)
46:59:591 mix sound th D[SCEKERNEL]: HLE\sceKernelSemaphore.cpp:293 sceKernelSignalSema(299, 1) (count: 0 -> 1)
46:59:591 mix sound th D[ME]: HLE\sceAtrac.cpp:1204 0=sceAtracAddStreamData(0, 00001660)
46:59:591 mix sound th D[ME]: HLE\sceAtrac.cpp:1598 sceAtracGetNextDecodePosition(0, 09fee680)
46:59:591 mix sound th D[ME]: HLE\sceAtrac.cpp:1642 sceAtracGetNextSample(0, 09fee684): 24 samples left
46:59:592 mix sound th I[ME]: HW\MediaEngine.cpp:103 FF: Channel unit extension
46:59:592 mix sound th I[ME]: HW\MediaEngine.cpp:103 FF:  is not implemented. Update your FFmpeg version to the newest one from Git. If the problem still occurs, it means that your file has a feature which has not been implemented.
46:59:592 mix sound th E[ME]: HLE\sceAtrac.cpp:602 Unsupported feature in ATRAC audio.
46:59:592 mix sound th D[ME]: HLE\sceAtrac.cpp:1398 00000000=sceAtracDecodeData(0, 08d6031c, 08b5c2f4[00000018], 08b5c2e0[00000000], 08b5c2d4[181])
46:59:592 idle0        D[SCEKERNEL]: HLE\sceKernelThread.cpp:3087 Context switch: mix sound thread -> idle0 (340->272, pc: 08a6da94->08000000, atrac decode data) +12us
46:59:592 mix sound th D[SCEKERNEL]: HLE\sceKernelThread.cpp:3087 Context switch: idle0 -> mix sound thread (272->340, pc: 08000000->08a6da94, woke from hle delay) +2300us
46:59:592 mix sound th D[SCEKERNEL]: HLE\sceKernelEventFlag.cpp:513 0=sceKernelPollEventFlag(336, ffffffff, 00000001, 08b5c2cc[00000028])
46:59:592 mix sound th D[ME]: HLE\sceAtrac.cpp:1666 0=sceAtracGetRemainFrame(0, 09fee660[000000b5])
46:59:592 mix sound th D[ME]: HLE\sceAtrac.cpp:1598 sceAtracGetNextDecodePosition(0, 09fee680)
46:59:592 mix sound th D[ME]: HLE\sceAtrac.cpp:1642 sceAtracGetNextSample(0, 09fee684): 2048 samples left
46:59:592 mix sound th I[ME]: HW\MediaEngine.cpp:103 FF: Invalid start bit!
46:59:592 mix sound th E[ME]: HLE\sceAtrac.cpp:607 avcodec_decode_audio4: Error decoding audio -1094995529 / bebbb1b7
46:59:592 mix sound th D[ME]: HLE\sceAtrac.cpp:1398 80630024=sceAtracDecodeData(0, 08d6037c, 08b5c2f4[00000000], 08b5c2e0[00000001], 08b5c2d4[0])
46:59:592 mix sound th E[ME]: HLE\sceAtrac.cpp:1565 UNIMPL sceAtracGetInternalErrorInfo(0, 09fee688)
46:59:592 mix sound th D[SCEKERNEL]: HLE\sceKernelEventFlag.cpp:312 0=sceKernelSetEventFlag(336, 00000004)
46:59:592 mix sound th D[SCEKERNEL]: HLE\sceKernelEventFlag.cpp:271 0=sceKernelClearEventFlag(336, ffffffdf)
46:59:592 mix sound th D[SCEKERNEL]: HLE\sceKernelEventFlag.cpp:312 0=sceKernelSetEventFlag(336, 00000004)
46:59:592 mix sound th D[SCEKERNEL]: HLE\sceKernelEventFlag.cpp:513 0=sceKernelPollEventFlag(336, ffffffff, 00000001, 08b5c2cc[0000000c])
46:59:592 mix sound th D[ME]: HLE\sceAtrac.cpp:1666 0=sceAtracGetRemainFrame(0, 09fee660[000000b5])
46:59:592 mix sound th D[SCEKERNEL]: HLE\sceKernelEventFlag.cpp:271 0=sceKernelClearEventFlag(336, ffffffdf)
46:59:592 mix sound th D[SCEIO]: HLE\sceIo.cpp:2175 0=sceIoCloseAsync(9)
46:59:592 mix sound th D[SCEKERNEL]: HLE\sceKernelEventFlag.cpp:513 0=sceKernelPollEventFlag(336, ffffffff, 00000001, 08b5c2cc[0000000c])
46:59:592 mix sound th D[SCEKERNEL]: HLE\sceKernelSemaphore.cpp:401 0=sceKernelWaitSema(337, 1, 0)
46:59:592 SceIoAsync   D[SCEKERNEL]: HLE\sceKernelThread.cpp:3087 Context switch: mix sound thread -> SceIoAsync (340->364, pc: 08b1824c->08220e00, sas core) +28us
46:59:592 SceIoAsync   D[SCEIO]: HLE\sceIo.cpp:2956 ASYNC 0 = sceIoCloseAsync(9)
46:59:592 idle0        D[SCEKERNEL]: HLE\sceKernelThread.cpp:3087 Context switch: SceIoAsync -> idle0 (364->272, pc: 08220e00->08000000, async io) +8us

[sum2012]

@arqarq how to reproduce that new error ?

[arqarq]

I'm not sure how to trigger this error; it seems to occur randomly. But I know how to "remove" the error related to channels. Literally "remove" it. I prepared stereo versions of the files 'CITY_LONGLOOP8BIT.AT3' and 'CITY_LONGLOOP8BIT_WITHRAIN.AT3', and the playback also stops, but without this message! Weird. Then I used another file 'DRAGON_LOOP.AT3' (which is stereo in the game) with the same name as the above ambient ones, and the playback doesn't stop.
Ultimately, I prepared versions of files 'CITY_*' that are over an hour long, and that solved the problem. The sound is still mixed (e.g., it turns off in cutscenes, switches to the rainy version and back) and the problem is solved (with the 1.17.1; I haven't tested self-built version for too long). It seems to be a problem with looping those 40s files. I don't know why this game has such a high compatibility rating; this sound isn't optional music, it builds atmosphere, but perhaps only for me.

[DAIndigoMouse]

Thanks for the help in regards to fixing this problem it took me a while to figure it out but now that I have I can finally enjoy this awesome game.