aaudio crash, assert in releaseBuffer

[taemincho]

Hi, we've published a beta version app which first uses Oboe, and got reported a lot of crashes look similar to below:

#00 pc 000000000001a48c /system/lib/libc.so (abort+63)
#1 pc 00000000000065c3 /system/lib/liblog.so (__android_log_assert+154)
#2 pc 00000000000340f9 /system/lib/libaudioclient.so (android::ClientProxy::releaseBuffer(android::Proxy::Buffer*)+120)
#3 pc 0000000000024c3b /system/lib/libaudioclient.so (android::AudioRecord::releaseBuffer(android::AudioRecord::Buffer const*)+66)
#4 pc 0000000000024d3d /system/lib/libaudioclient.so (android::AudioRecord::read(void*, unsigned int, bool)+212)
#5 pc 000000000001371d /system/lib/libaaudio.so (aaudio::AudioStreamRecord::read(void*, int, long long)+92)
oboe::AudioStreamAAudio::read(void*, int, long long) at /android/oboe/src/aaudio/AudioStreamAAudio.cpp:372:26

Any idea what could cause these crashes ?

[atneya]

Are there any other details when/how the crash is caused?

Are you using callback methods or blocking reads/writes?

Any specific device versions/API levels?

A preliminary guess is the AudioStream is closed, while a blocking read is pending, causing a crash when the read attempts to access the closed stream. However, any additional details would be extremely helpful.

[taemincho]

Thank you, I found that this could happen when our app goes background.

[dturner]

Hey @taemincho, any chance you can share a few more details of the problem so that we can advise other developers on how to avoid the issue? Closing streams is a particularly tricky topic.

[philburk]

You are using a blocking read.
oboe::AudioStreamAAudio::read(void*, int, long long)

Perhaps the stream is being closed by another stream while the read is still blocked.
It sounds similar to this:
#359

Do you have this fix?
#364

[taemincho]

Sorry for the late reply, I was on vacation.
We're using 1.2-stable version, and I'm sure it has #364 fix.

We created input stream and output stream and used a blocking read from the input stream inside the output stream callback.
We closed the input and output streams in various situations such as when the output stream's onErrorAfterClose is called (AAudio only), when headphone plugged in/out, when the app lost audio focus and etc.
So yes, it was possible to be being closed the input stream while oboe::AudioStreamAAudio::read(void*, int, long long) is still blocked.
Now, I set a lock for preventing the input stream is being closed while the read is blocked.

However we still get many crashes that look like below

#00 pc 0000000000049c64 /system/lib/libc.so (tgkill+12)
#1 pc 0000000000047403 /system/lib/libc.so (pthread_kill+34)
#2 pc 000000000001d555 /system/lib/libc.so (raise+10)
#3 pc 00000000000190a1 /system/lib/libc.so (__libc_android_abort+34)
#4 pc 0000000000017104 /system/lib/libc.so (abort+4)
#5 pc 000000000000c3d9 /system/lib/libcutils.so (__android_log_assert+112)
#6 pc 000000000006f8f9 /system/lib/libmedia.so (_ZN7android11ClientProxy13releaseBufferEPNS_5Proxy6BufferE+88)
#7 pc 000000000006ce4b /system/lib/libmedia.so (_ZN7android10AudioTrack13releaseBufferEPKNS0_6BufferE+82)
#8 pc 000000000006d6e7 /system/lib/libmedia.so (_ZN7android10AudioTrack18processAudioBufferEv+1654)
#9 pc 000000000006ee9b /system/lib/libmedia.so (_ZN7android10AudioTrack16AudioTrackThread10threadLoopEv+130)
#10 pc 000000000000e4b1 /system/lib/libutils.so (_ZN7android6Thread11_threadLoopEPv+264)
#11 pc 0000000000046ed3 /system/lib/libc.so (_ZL15__pthread_startPv+22)
#12 pc 0000000000019aed /system/lib/libc.so (__start_thread+6)

Any ideas?

FYI: I found the same error reported in Stack Overflow.
https://stackoverflow.com/questions/46403487/android-weird-audiotrack-crash

[milos-pesic-sc]

I can also report that we are experiencing relatively frequent crash which matches with the stack overflow post @taemincho posted in the comment above:

backtrace:
  #00  pc 000000000001ceae  /system/lib/libc.so (abort+58)
  #01  pc 0000000000006d0d  /system/lib/liblog.so (__android_log_assert+156)
  #02  pc 000000000003bd4d  /system/lib/libaudioclient.so (android::ClientProxy::releaseBuffer(android::Proxy::Buffer*)+108)
  #03  pc 0000000000036da3  /system/lib/libaudioclient.so (android::AudioTrack::releaseBuffer(android::AudioTrack::Buffer const*)+78)
  #04  pc 0000000000037765  /system/lib/libaudioclient.so (android::AudioTrack::processAudioBuffer()+1908)
  #05  pc 0000000000039501  /system/lib/libaudioclient.so (android::AudioTrack::AudioTrackThread::threadLoop()+128)
  #06  pc 000000000000c107  /system/lib/libutils.so (android::Thread::_threadLoop(void*)+290)
  #07  pc 0000000000064829  /system/lib/libc.so (__pthread_start(void*)+140)
  #08  pc 000000000001e375  /system/lib/libc.so (__start_thread+24)

We use callbacks and not blocking reads though.
Based on some crashlytics logs for this issue - as far as I can see - the crash appears in two situations 1) at the beginning of a track - when we start the stream
2) after ErrorDisconnected error (where we recreate and restart the stream). Last log lines I can see in this case:

D/CrashlyticsCore [2019-06-24 13:51:56.944349 (tid:3445725552)] - onErrorBeforeClose - Error on AudioStream : ErrorDisconnected
D/CrashlyticsCore [2019-06-24 13:51:56.946371 (tid:3445725552)] - onErrorBeforeClose - AudioStream device id: 317
D/CrashlyticsCore [2019-06-24 13:51:56.947362 (tid:3445725552)] - onErrorAfterClose - Error on AudioStream ErrorDisconnected
D/CrashlyticsCore [2019-06-24 13:51:56.947500 (tid:3445725552)] - restartStream - Restarting stream
D/CrashlyticsCore [2019-06-24 13:51:56.955914 (tid:3445725552)] - internalCreateStream - AudioStream opened. Device id: 1
D/CrashlyticsCore [2019-06-24 13:51:56.956079 (tid:3445725552)] - onErrorAfterClose - Error after close callback done

[atneya]

This is an assert failure in libaudioclient. Do either of you have a full logcat of the crash (including libaudioclient error messages)? That would make debugging this particular issue much easier, since it seems difficult to reproduce.

[milos-pesic-sc]

@atneya Unfortunately - we don't. We don't collect full logcat from the field and we couldn't reproduce the issue in house.

[milos-pesic-sc]

But maybe device list from developer console for the crash could help:

HWVOG	271	9.6%
HWINE	158	5.6%
starqltesq	134	4.8%
HWMAR	115	4.1%
HWJSN-H	110	3.9%
HWEML	109	3.9%
crownqltesq	109	3.9%
HWANE	99	3.5%
star2qltesq	96	3.4%
HWELE	94	3.3%
dreamqltesq	83	2.9%
HWJKM-H	74	2.6%
beyond2q	65	2.3%
dream2qltesq	60	2.1%
HWPOT-H	56	2.0%
greatqlte	52	1.8%
HWLYA	52	1.8%
j4corelte	48	1.7%
HWVTR	46	1.6%
HWHRY-H	42	1.5%
Others	944	33.5%

[atneya]

@milos-pesic-sc
The device list is actually quite helpful -- all of the devices listed are Samsung/Huawei , which makes the issue easier to pinpoint, and perhaps explains the difficulty in reproducing it.

Are you able to get a full list of devices (expand Others) to confirm?

It is unlikely that this is an Oboe specific issue (especially considering the StackOverflow post linked refers to using OpenSLES), however all additional information makes debugging the underlying issue easier. Although, perhaps Oboe is exacerbating/exposing an underlying issue, and we can implement a workaround.

Did you encounter this issue when using OpenSLES without Oboe in the past?

@taemincho
The original stack trace referred was on the input side, using blocking reads. The second stack trace uses callbacks on the output side.

Were the original crashes on the input side resolved by using a lock? Were the output crashes present prior as well?

Do you have any additional device details/logs/information regarding when the crash occurs?