hrydgard / ppsspp

A PSP emulator for Android, Windows, Mac and Linux, written in C++. Want to contribute? Join us on Discord at https://discord.gg/5NJB6dD or just send pull requests / issues. For discussion use the forums at forums.ppsspp.org.
https://www.ppsspp.org
Other
11.02k stars 2.15k forks source link

avcodec_decode_audio4 in Grand Theft Auto: Chinatown Wars #18923

Open arqarq opened 6 months ago

arqarq commented 6 months ago

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

anr2me commented 6 months ago

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

sum2012 commented 6 months ago

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 commented 6 months ago

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

ffplay

sum2012 commented 6 months ago

@arqarq I have switched the Media log level to debug

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

anr2me commented 6 months ago

seem revert #18414 + apply #18396 fix the issue

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

sum2012 commented 6 months ago

seem revert #18414 + apply #18396 fix the issue

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

No

arqarq commented 6 months ago

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

sum2012 commented 6 months ago

Need more testing

arqarq commented 6 months ago

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

arqarq commented 6 months ago

Unfortunately, it still occurs (own build with -https://github.com/hrydgard/ppsspp/pull/18414 / +https://github.com/hrydgard/ppsspp/pull/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 commented 5 months ago

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 commented 5 months ago

@arqarq how to reproduce that new error ?

arqarq commented 5 months ago

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 'DRAGONLOOP.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 commented 2 months ago

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.