Rpcs3: Broken audio cause by Audio Buffering

Created on 15 May 2019  ·  18Comments  ·  Source: RPCS3/rpcs3

Hardware: 8700K OC, 32GB RAM, RTX 2080Ti
Game: Project Diva F 2nd (NBJP00435)
Audio Output: XAudio2 (i'll test later OpenAL)
Reproduce steps: Open the game and do 1~3 game play
I've tried several custom builds and I found that #5456 (commit 2addbe6) caused this.
I know there are something called "audio buffer" but it is disaster to add random latency to rhythm games.
There are several audio errors in log

S RSX: New program compiled successfully x179
U {PPU[0x1000000] Thread (main_thread) [0x006a3e8c]} cellSysutil TODO: cellVideoOutConfigure(videoOut=0, config=*0xd0058a20, option=*0x0, waitForEvent=0)
U {PPU[0x1000008] Thread (libusbd_callback_thread) [0x01395ad4]} sys_usbd TODO: sys_usbd_receive_event(handle=805322496, arg1=0xd00a1f50, arg2=0xd00a1f58, arg3=0xd00a1f60)
E {PPU[0x1000000] Thread (main_thread) [0x0034bc30]} 'cellKbClearBuf' failed with 0x80121007 : CELL_KB_ERROR_NO_DEVICE [1]
E {PPU[0x1000000] Thread (main_thread) [0x00679e08]} 'sys_mutex_lock' failed with 0x80010008 : CELL_EDEADLK [1]
E {PPU[0x1000000] Thread (main_thread) [0x0067a8e0]} 'sys_mutex_unlock' failed with 0x80010009 : CELL_EPERM [1]
S {cellAudio Thread} XAudio 2.9 initialized
E {PPU[0x1000013] Thread (_sys_MixerChStripMain) [0x012654ec]} '_sys_lwmutex_lock' failed with 0x80010005 : CELL_ESRCH [1]
E {PPU[0x1000013] Thread (_sys_MixerChStripMain) [0x012654ec]} '_sys_lwmutex_lock' failed with 0x80010005 : CELL_ESRCH [2]
E {PPU[0x1000013] Thread (_sys_MixerChStripMain) [0x012654ec]} '_sys_lwmutex_lock' failed with 0x80010005 : CELL_ESRCH [3]
E {PPU[0x1000015] Thread (_cellsurMixerMain) [0x0066ca08]} 'sys_mutex_lock' failed with 0x80010008 : CELL_EDEADLK [1]
E {PPU[0x1000015] Thread (_cellsurMixerMain) [0x0066ca08]} 'sys_mutex_lock' failed with 0x80010008 : CELL_EDEADLK [2]
E {PPU[0x1000015] Thread (_cellsurMixerMain) [0x0066ca08]} 'sys_mutex_lock' failed with 0x80010008 : CELL_EDEADLK [3]
**E {cellAudio Thread} cellAudio: Audio backend stopped unexpectedly, likely due to a buffer underrun x4**
E {PPU[0x1000000] Thread (main_thread) [0x00672ca4]} cellSaveData: cellSaveDataEnableOverlay(enable=1)
E {PPU[0x1000000] Thread (main_thread) [0x00018234]} cellSaveData: cellSaveDataEnableOverlay(enable=0)
E {PPU[0x1000000] Thread (main_thread) [0x00672ca4]} cellSaveData: cellSaveDataEnableOverlay(enable=1)
E {PPU[0x1000000] Thread (main_thread) [0x00018234]} cellSaveData: cellSaveDataEnableOverlay(enable=0)
**E {cellAudio Thread} cellAudio: Audio backend stopped unexpectedly, likely due to a buffer underrun x5**
E {PPU[0x1000000] Thread (main_thread) [0x00672ca4]} cellSaveData: cellSaveDataEnableOverlay(enable=1)
E {PPU[0x1000000] Thread (main_thread) [0x00018234]} cellSaveData: cellSaveDataEnableOverlay(enable=0)
**E {cellAudio Thread} cellAudio: Audio backend stopped unexpectedly, likely due to a buffer underrun x11**
E {PPU[0x100001b] Thread (thr_install) [0x00915ee0]} sceNpTrophy: sceNpTrophyRegisterContext(context=0x1, handle=0x1, statusCb=*0xa1b620, arg=*0x100f6b0, options=0x1)
**E {cellAudio Thread} cellAudio: Audio backend stopped unexpectedly, likely due to a buffer underrun x13**
E {PPU[0x1000021] Thread (diva_batch) [0x00581998]} sceNpTrophy: sceNpTrophyGetTrophyUnlockState(context=0x1, handle=0x1, flags=*0xd00b0d5c, count=*0xd00b0d48)
**E {cellAudio Thread} cellAudio: Audio backend stopped unexpectedly, likely due to a buffer underrun x9**
E {PPU[0x1000000] Thread (main_thread) [0x01331ee4]} 'sys_fs_stat' failed with 0x80010006 : CELL_ENOENT, “/dev_hdd0/game/NPJB00435_DATA/USRDIR/net/netdata.bin” [1]
E {PPU[0x1000000] Thread (main_thread) [0x01331ee4]} 'sys_fs_stat' failed with 0x80010006 : CELL_ENOENT, “/dev_hdd0/game/NPJB00435_DATA/USRDIR/net/netdata.bin” [2]
**E {cellAudio Thread} cellAudio: Audio backend stopped unexpectedly, likely due to a buffer underrun**
U {PPU[0x1000000] Thread (main_thread) [0x0034c430]} cellScreenshot TODO: cellScreenShotEnable()
**E {cellAudio Thread} cellAudio: Audio backend stopped unexpectedly, likely due to a buffer underrun x2**
E {PPU[0x1000000] Thread (main_thread) [0x00672ca4]} cellSaveData: cellSaveDataEnableOverlay(enable=1)
E {PPU[0x1000000] Thread (main_thread) [0x00018234]} cellSaveData: cellSaveDataEnableOverlay(enable=0)
**E {cellAudio Thread} cellAudio: Audio backend stopped unexpectedly, likely due to a buffer underrun x16**
U {PPU[0x1000000] Thread (main_thread) [0x00672ca4]} cellScreenshot TODO: cellScreenShotDisable()
E {PPU[0x1000000] Thread (main_thread) [0x00672ca4]} cellSaveData: cellSaveDataEnableOverlay(enable=1)
E {PPU[0x1000000] Thread (main_thread) [0x00018234]} cellSaveData: cellSaveDataEnableOverlay(enable=0)
E {PPU[0x1000000] Thread (main_thread) [0x00672ca4]} cellSaveData: cellSaveDataEnableOverlay(enable=1)
E {PPU[0x1000000] Thread (main_thread) [0x00018234]} cellSaveData: cellSaveDataEnableOverlay(enable=0)
E {PPU[0x1000000] Thread (main_thread) [0x00672ca4]} cellSaveData: cellSaveDataEnableOverlay(enable=1)
E {PPU[0x1000000] Thread (main_thread) [0x00018234]} cellSaveData: cellSaveDataEnableOverlay(enable=0)
U {PPU[0x1000000] Thread (main_thread) [0x0034c430]} cellScreenshot TODO: cellScreenShotEnable() x2
S {RSX Decompiler Thread} RSX: New program compiled successfully x52
E {PPU[0x1000000] Thread (main_thread) [0x00672ca4]} cellSaveData: cellSaveDataEnableOverlay(enable=1)
E {PPU[0x1000000] Thread (main_thread) [0x00018234]} cellSaveData: cellSaveDataEnableOverlay(enable=0)
S {RSX Decompiler Thread} RSX: New program compiled successfully x5

Most helpful comment

First things first, isn't this a bit off-topic? Please go to Discord if you want to have a conversation, github is not the place for that.

Second, you cannot buffer or time stretch audio or avoid audio crackle or whatever else without adding latency. What audio do you propose we stretch if there's no audio buffered?

Let alone the fact that a "0ms audio buffer" is a completely stupid concept. The PS3 architecture buffers audio 5.(3)ms ahead, so <5.(3)ms buffer is impossible. Disabling "audio buffering" is effectively the same as setting the buffer size to 5.(3)ms.

Additionally, the PS3 has an additional audio latency (from the ringbuffer down to the audio output, plus whatever latency your TV adds on top) that is unknown, but likely significant. I can bet that 20ms audio buffer with a decent audio driver, no post-processing, and connected to a good sound system has lower latency than a real PS3 would connected to a TV.

Also, do you really know how much 5.3ms of audio is? Audio stutter is likely to be >1ms worth. If you stretch 5.3ms audio to fit in 6.3ms, your ears will bleed. Even 100ms stretched to 105ms is already pretty noticeable.

All 18 comments

It's not broken, it's by design. And that's why there's an option to disable it as well.
The errors in your log suggest your cpu is underpowered, but as you didn't follow the guidelines for proper issue submission, there's no way to tell anything.

@13xforever Sorry for my bad English.
I mean the audio contains lots of noise after several minutes of gameplay. And of course I disabled it before the test.
There is not much CPU better then 8700K atm. And i'm sure I provided all necessary informations listed in .github/ISSUE_TEMPLATE.md

@kotori2 you mean to say audio is bad irrespective of whether Audio buffering is enabled or disabled?

@HerrHulaHoop nah, only on Audio buffering disabled

This is not caused by audio buffering. As you yourself state, enabling audio buffering fixes the stutter.

That error means that the game did not provide audio fast enough, and as such the audio buffer ran out of audio to play.

As such, either you have wrong settings, or your CPU is too slow for this game. Try reading the forum compatibility threads for this game to find better settings, or come to #help on Discord.

If you are sure that 2addbe6 is the first commit where you hear any stutter, then you can try changing

https://github.com/RPCS3/rpcs3/blob/3753d27aba27af07615c87bdb56d5854bef8c372/rpcs3/Emu/Cell/Modules/cellAudio.h#L337 to
return 1000;
which should more closely match the pre-buffering audio timings (which were a hack).

Note that this will break audio if buffering is enabled, just curious if it improves non-buffered audio.

@ruipin Thanks for reply.
Although fps meter always flickering around 60fps(59-61), it does little lag some time. So it could possibly caused by lack of performance.
I've tried your fix but it seems doesn't work. It still broke after I clear the cache and 2 gameplay.
I'm going to try to reproduce on e18e990 to see if this persist. I submit this issue because it all works fine way back to v0.0.[3-5] so I'm digging informations.
By the way when graphic is slower then audio, can audio lag for about 10 milliseconds and wait for graphic frames or even drop frames instead of broke the audio?

Audio and graphics "framerate" are not necessarily related, it depends on how games handle audio. You could have 60FPS graphics and audio stutter, or 5FPS graphics and perfect audio.

As for "wait for audio frames", that's not really possible without introducing latency. Audio buffering already attempts to do that, which is why it doesn't stutter.

If nothing else works, you can always enable audio buffering and set a low latency (e.g. the minimum allowed in the UI which is 20ms). That should be more than enough to fix the stutter, and still not enough latency to affect the gameplay.

@ruipin It seem I really can't reproduce it on commit e18e990, right before your pr. Maybe you can test it out on your low end CPU. I still suspect there is something wrong with that patch instead of performance decrease.

I still don't think this is a bug.

Okay I'm going to close this since you don't think this is a bug and I don't want to reproduce on any other situation. If anyone found same issue, comment below and I will reopen it.

I was experiencing that thing too (audio crackling and audio desync on xaudio2 with disabled buffer), openal just give me noticeable latency (maybe ~ 100ms with buffer disabled) that because openal is slow audio renderer (i know that from someone on rpcs3 discord server), but no audio crackling.

When that audio crackling happened ,u can pause the emu and resume it again, but that not fix it permanently.

Btw when i play that game on fullscreen and w/o vsync , it just give me frameskip and audio crackling. But work perfectly on windowed mode or with vsync enabled (no frameskip and no audio crackling). That happened on vulkan renderer (audio settings doesnt matter in this case) and maybe that only happened with nvidia user (btw i never test it on opengl, because opengl give me unplayable fps)

For audio desync ,enabling spu loop detection fix the problem (i have try disable it and the desync starting when the fps went back to normal after fps drop, longer fpsdrop duration = higher desync ).

And i agree with enabling buffer not good for rythm game, 20ms is still noticeable,if the buffer can be lower (ex.:1ms or 0ms) that would be good.

And i wouldn't recommend 60fps patch because i experiencing so bad performance on "Decorator".

I'm using low end laptop (i3 6006u,nvidia geforce mx110,4gb ddr4 2133mhz ram)

Thanks

Btw sorry for my bad english.

@GFigo I have EXACTLY same experience then you. But I was playing on window mode due to #5351, maybe I should try toggle Vsync switch.

Audio Buffer means you store audio streams in the past milliseconds in cache and play it. Higher value means you have lower chance to get crackling. Anyway I think you can modify config.yml manually to see what will happen.

Audio desync was fix long ago, maybe 0.0.3, I didn't notice such problem on all 4 Project Diva games.

As for 60 fps patch, the game may failed to decode some videos and make it buggy, I've tried to convert videos to 60 fps but it seems it will not recognize the format that I converted.

By the way when graphic is slower then audio, can audio lag for about 10 milliseconds and wait for graphic frames or even drop frames instead of broke the audio?

@kotori2 maybe you can try timestretching in audio settings

@GFigo Oh I think can set a 0 buffer and enable timestretch? Sounds problem solved! I will try tomorrow, thanks for that hint

@kotori2 you cant setu buffer to 0 nor lower than 20ms from config.yml. Just try to enable timestrecthing and set the percentage.

First things first, isn't this a bit off-topic? Please go to Discord if you want to have a conversation, github is not the place for that.

Second, you cannot buffer or time stretch audio or avoid audio crackle or whatever else without adding latency. What audio do you propose we stretch if there's no audio buffered?

Let alone the fact that a "0ms audio buffer" is a completely stupid concept. The PS3 architecture buffers audio 5.(3)ms ahead, so <5.(3)ms buffer is impossible. Disabling "audio buffering" is effectively the same as setting the buffer size to 5.(3)ms.

Additionally, the PS3 has an additional audio latency (from the ringbuffer down to the audio output, plus whatever latency your TV adds on top) that is unknown, but likely significant. I can bet that 20ms audio buffer with a decent audio driver, no post-processing, and connected to a good sound system has lower latency than a real PS3 would connected to a TV.

Also, do you really know how much 5.3ms of audio is? Audio stutter is likely to be >1ms worth. If you stretch 5.3ms audio to fit in 6.3ms, your ears will bleed. Even 100ms stretched to 105ms is already pretty noticeable.

@ruipin So the only solution is to add little buffer or buy a 7980XE?
I just thought timestretch is to stretch the currerent buffer instead all buffers later

Was this page helpful?
0 / 5 - 0 ratings