CrashIfClientProvidedBogusAudioBufferList: reference #17494

[guilhemvors]

• cocos2d-x version: 3.17
• devices test on: iphone 8
• Xcode version: 9.4.1

Steps to Reproduce:

1. Just create a cpp-empty-test with this code:

auto startButton = ui::Button::create();
startButton->setTitleText("START");
startButton->setPosition(visibleSize * 0.5f + Size(-100, 0));
this->addChild(startButton);
startButton->addTouchEventListener([=](Ref* sender, ui::Widget::TouchEventType type)
                                  {
                                      if (type == ui::Widget::TouchEventType::ENDED)
                                      {
                                          auto testBogusAudio = [this](float dt) {
                                              AudioEngine::play2d("iphone/combo_1.mp3", false, 1.0f);
                                              AudioEngine::play2d("iphone/combo_2.mp3", false, 1.0f);
                                          };
                                          cocos2d::Director::getInstance()->getScheduler()->schedule(testBogusAudio, this, 0.f, false, "AudioSwitchStateTest");
                                      }
                                  });
    
auto stopButton = ui::Button::create();
stopButton->setTitleText("STOP");
stopButton->setPosition(visibleSize * 0.5f + Size(100, 0));
this->addChild(stopButton);
stopButton->addTouchEventListener([=](Ref* sender, ui::Widget::TouchEventType type)
                                       {
                                           if (type == ui::Widget::TouchEventType::ENDED)
                                           {
                                               AudioEngine::uncacheAll();
                                               cocos2d::Director::getInstance()->getScheduler()->unschedule("AudioSwitchStateTest", this);
                                           }
                                       });

2. Launch the test and click on the start/stop button several times: the crash is kind of elusive and doesn't occurs everytime, it may take a few minutes to have it.

Log: https://textuploader.com/dz77q
Stack of the crash: https://textuploader.com/dz77l
Link to the combo_1.mp3 & combo_2.mp3:
https://www.dropbox.com/s/jp60anbxhgjyi17/combo_1.mp3?dl=0
https://www.dropbox.com/s/2n9uvr39nvx12hp/combo_2.mp3?dl=0

Primary analysis:
The commit that *may fix the bug by delaying the destruction of the _pcmData in the audio crash doesn't solve the problem (see this issue: #17494).

From what I have gathered:

1°) if you comment the free(_pcmData) (which cause memory leak obviously), the crash doesn't occur. Which means that it's really the deletion of the _pcmData that causes the problem.
2°) having more than 2 sounds (tested with 10 sounds) doesn't seems to increase the appearance of the crash, I think it's due to the fact that even with 2 sound, as we are scheduling them at a 0ms schedule, we are already hitting the max played sound instance hard cap.
3°) Calling free(_pcmData) just after the decoder.read in the readDataTask method doesn't produce the crash. From the API specification apple says that ExtAudioFileRead is synchronous.

The only conclusion I can come up with is that destroying the pcmData buffer in the main thread, while the URemoteIO thread is still performing tasks leads to the crash. The question now is when exactly does the free(pcmData) needs to occur to cause the crahs.

I don't really know what would be the preferred way to handle it, as adding more time to the delay before free (as we have seen) doesn't seem to be a robust solution, plus it has the negative effect of effectively freeing the resource at a later time than what we would expect, which is a problem in a state-based game, audio resources from the previous scene might not be released immediately during destroy object operation, leading to potentially spike in RAM usage when the assets of the new scene are loaded up in memory while the old audioBuffer are still in memory too.

I see three potential way of dealing with it:

• having a way to stop the DoRender method of the AURemoteIO at the moment we destroy the pcmData, but I am not familiar enough with Core audio to know if it's possible.
• delay the destruction of the buffer until the AudioRenderTask is done (which is not ideal, as described above)
• locking the main thread (and the destruction of the AudioCache) until the AURemoteIO thread has finished its tasks?

@dumganhar @drelaptop could you please look into it? It is easy to reproduce and we are several to report this issue.

Sorry for the wall of text and thank you very much.

[guilhemvors]

link to the stackoverflow question: https://stackoverflow.com/questions/51426621/is-there-a-way-to-stop-the-auremoteio-thread-from-the-autiotoolbox-from-performi

[dumganhar]

I have left Cocos team. You could ask @minggo and @leda for help. guilhemvors <notifications@github.com> 于 2018年7月19日周四 23:32写道：

…

link to the stackoverflow question: https://stackoverflow.com/questions/51426621/is-there-a-way-to-stop-the-auremoteio-thread-from-the-autiotoolbox-from-performi — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#18948 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAeHPG5SS_WCp0wy21d0g_Rxd8_c0Mc5ks5uIKaegaJpZM4VWe28> .

[guilhemvors]

Further notes:

• the console logs between the crashing and non-crashing execution doesn't differs.
• There is a hipcut in our usage of ExtFileAudioRead in the AudioDecoder. From the standard it is said that it must only be used for reading audio file from the SAME THREAD (https://developer.apple.com/documentation/audiotoolbox/1486821-extaudiofileread?language=objc). So the implementation needs to be rewrote using AudioFileService instead, because we are calling the readDataTask method from different threads. HOWEVER, when tested with using readDataTask only from the main thread, the crash still occurs. Which means that even if our usage is not standard compliant, it doesn't seems to be the cause of the crash.
• There is another hipcut in our usage of the alBufferDataStaticProc in the destructor of the AudioCache:

if (_pcmData)
    {
        if (_state == State::READY)
        {
            if (_alBufferId != INVALID_AL_BUFFER_ID && alIsBuffer(_alBufferId))
            {
                ALOGV("~AudioCache(id=%u), delete buffer: %u", _id, _alBufferId);
                alDeleteBuffers(1, &_alBufferId);
                _alBufferId = INVALID_AL_BUFFER_ID;
            }
        }
        else
        {
            ALOGW("AudioCache (%p), id=%u, buffer isn't ready, state=%d", this, _id, _state);
        }

        // fixed #17494: CrashIfClientProvidedBogusAudioBufferList
        // We're using 'alBufferDataStaticProc' for speeding up
        // the performance of playing audio without preload, but we need to manage the memory by ourself carefully.
        // It's probably that '_pcmData' is freed before OpenAL finishes the audio render task,
        // then 'CrashIfClientProvidedBogusAudioBufferList' may be triggered.
        // 'cpp-tests/NewAudioEngineTest/AudioSwitchStateTest' can reproduce this issue without the following fix.
        // The workaround is delaying 200ms to free pcm data.
        char* data = _pcmData;
         setTimeout(0.2, [data]() { free(data); });
    }

As per the standard (https://opensource.apple.com/source/OpenAL/OpenAL-61/Source/OpenAL/READ_ME.auto.html), in AL_EXT_STATIC_BUFFER, it is said that the deletion of the buffers should always happen after a SUCCESSFULL call to alDeleteBuffer, but in the destructor we don't check if the call to alDeleteBuffer returned without error. HOWEVER when tested with the error checking code, when the crash occurs, it appears that there is no error in openAL, which means that this hipcut is not the cause of the crash either.

• Finally, when I ran the code in the simulator with thread sanitizer ON, there were a LOT of data races on multiple variables, for example on _isDestroyed, _isLaodingFinished, _isSkipReadDataTask etc etc, both in the AudioCaches and in the AudioEngineImpl. HOWEVER, even after correcting theses data races using C++ atomics were needed, the crash still occured, which means that those data races are not the cause of the bug.

[guilhemvors]

After a deeper investigation, I know exactly what is happening:

When looking in the convertFile project from the Audio Core apple example (https://developer.apple.com/library/archive/samplecode/ConvertFile/Introduction/Intro.html then download sample code), in the useAC-AF.cpp file, we have the actual implementation of the method used internally to convert non linear pcm data to linear pcm data.

While it is said that the call to ExtFileAudioRead is synchronous, when used with a non pcm data format, the ExtFileAudioRead method will actually call its internal AudioConverter object to convert the compressed audio data into linear pcm.

The problem is that the convertion is done in an update, inside the AURemoteIO::performIO, which is in its own thread (AURemoteIO::IOThread), and not on the thread we are performing our readDataTask.

What this means is that if we are freeing the pcm data from our thread, while the IOThread is converting it, it leads to memory corruption.

The only way I can see to solve this problem is actually to:

• don't use alBufferDataStaticProc, so we let openAL perform a copy of the audio data, and let him handle the memory of this datas, while we clean our pcmData immediately
• change the implementation of the decoder so that we are always giving the ExtFileAudioRead linear pcm data so that there is no need to convert it.

tell me what you think about it @drelaptop @minggo

[pablorealini]

We are experience this same issue, we still didn´t find a way to reproduce it.

[cigumo]

I've changed AudioCache.mm to use alBufferData instead of alBuffer and I got rid of the CrashIfClientProvidedBogusAudioBufferList crash, but another crash appeared, this time involving OpenAL's CleanUpDeadBufferList() calls.

As the _pcmData buffer is copied by OpenAL after alBufferData() is called, I removed the scary setTimeout() in ~AudioCache and changed _pcmData to be used just inside the readDataTask call (not in a very elegant way, but didn't want to change the code too much).

I understand that we're making an extra copy of the uncompressed audio in memory, but as the recommended use for non streaming sounds is for them to be small, it should not be a problem in modern hardware (it was a big issue on the original iPhone! :))

I also extended the coverage of _readDataTaskMutex in ~AudioCache to include the alDeleteBuffers() call, and this reduced the the CleanUpDeadBufferList() crashes a lot.

Here's the pull request in our fork for reference:
ironhidegames#2

It's very hard to reproduce with the change. To improve the odds I changed cpp-test 19 to trigger once every 10ms instead of the 100ms (also in the pull request)

The odds seem to improve if the device is "cold", which means after half an hour or more not using it and locked, but I cannot confirm.

The crash seems to be related to threading obviously, but I'm not experienced enough with the Cocos2D engine to be able to pinpoint exactly what is happening.

I include three sshots of the crash below, as reference (iOS 12 on iPhone 6S)

• 1. after 47 minutes
• 2. after 2 minutes
• 3. after 28 minutes

[drelaptop]

thanks to @guilhemvors @cigumo , #19227 comes, so developers can fix it.

I won't close this issue until some developers feedback that works.

[drelaptop]

more than one tested, that patch is good, so merge it and close this.