google / oboe

Oboe is a C++ library that makes it easy to build high-performance audio apps on Android.
Apache License 2.0
3.69k stars 563 forks source link

Crash in aaudio::AudioStreamLegacy::getBestTimestamp() #1489

Open extreamsd opened 2 years ago

extreamsd commented 2 years ago

Android version(s): 11 Android device(s): Samsung SM-T500 Oboe version: 1.6.1 App name used for testing: Audio Evolution Mobile Studio

I'm not sure if you are interested in these kind of stack traces since they are from customers who usually cannot reproduce issues, but here is the trace:

00 pc 000000000008cea4 /apex/com.android.runtime/lib64/bionic/libc.so (abort+164)

01 pc 0000000000025918 /system/lib64/libaaudio_internal.so (aaudio::AudioStreamLegacy::getBestTimestamp(int, long, long, android::ExtendedTimestamp*)+356)

02 pc 0000000000029d84 /system/lib64/libaaudio_internal.so (aaudio::AudioStreamTrack::getTimestamp(int, long, long)+220)

03 pc 000000000001e4e8 /data/app/~~rgPx6Ut9nfsdblOnLgTDjA==/com.extreamsd.aemobile--o34yNaqcH60uit7xcWmfA==/lib/arm64/libaeoboe.so (oboe::AudioStreamAAudio::getTimestamp(int, long, long)+108)

04 pc 000000000001e578 /data/app/~~rgPx6Ut9nfsdblOnLgTDjA==/com.extreamsd.aemobile--o34yNaqcH60uit7xcWmfA==/lib/arm64/libaeoboe.so (oboe::AudioStreamAAudio::calculateLatencyMillis()+60)

05 pc 000000000031214c /data/app/~~rgPx6Ut9nfsdblOnLgTDjA==/com.extreamsd.aemobile--o34yNaqcH60uit7xcWmfA==/lib/arm64/libCore.so (Transport::onAudioReady(oboe::AudioStream, void, int)+1668)

06 pc 000000000001ef70 /data/app/~~rgPx6Ut9nfsdblOnLgTDjA==/com.extreamsd.aemobile--o34yNaqcH60uit7xcWmfA==/lib/arm64/libaeoboe.so (non-virtual thunk to oboe::AudioSourceCaller::onProcessFixedBlock(unsigned char*, int)+80)

07 pc 00000000000224a8 /data/app/~~rgPx6Ut9nfsdblOnLgTDjA==/com.extreamsd.aemobile--o34yNaqcH60uit7xcWmfA==/lib/arm64/libaeoboe.so (FixedBlockReader::read(unsigned char*, int)+160)

08 pc 0000000000022948 /data/app/~~rgPx6Ut9nfsdblOnLgTDjA==/com.extreamsd.aemobile--o34yNaqcH60uit7xcWmfA==/lib/arm64/libaeoboe.so (oboe::SourceFloatCaller::onProcess(int)+52)

09 pc 0000000000027cbc /data/app/~~rgPx6Ut9nfsdblOnLgTDjA==/com.extreamsd.aemobile--o34yNaqcH60uit7xcWmfA==/lib/arm64/libaeoboe.so (oboe::flowgraph::FlowGraphPortFloatOutput::pullData(long, int)+128)

10 pc 0000000000027e14 /data/app/~~rgPx6Ut9nfsdblOnLgTDjA==/com.extreamsd.aemobile--o34yNaqcH60uit7xcWmfA==/lib/arm64/libaeoboe.so (oboe::flowgraph::FlowGraphSink::pullData(int)+72)

11 pc 0000000000029c70 /data/app/~~rgPx6Ut9nfsdblOnLgTDjA==/com.extreamsd.aemobile--o34yNaqcH60uit7xcWmfA==/lib/arm64/libaeoboe.so (oboe::flowgraph::SinkFloat::read(void*, int)+68)

12 pc 0000000000021bd8 /data/app/~~rgPx6Ut9nfsdblOnLgTDjA==/com.extreamsd.aemobile--o34yNaqcH60uit7xcWmfA==/lib/arm64/libaeoboe.so (non-virtual thunk to oboe::FilterAudioStream::onAudioReady(oboe::AudioStream, void, int)+72)

13 pc 000000000001f488 /data/app/~~rgPx6Ut9nfsdblOnLgTDjA==/com.extreamsd.aemobile--o34yNaqcH60uit7xcWmfA==/lib/arm64/libaeoboe.so (oboe::AudioStream::fireDataCallback(void*, int)+104)

14 pc 000000000001d9a4 /data/app/~~rgPx6Ut9nfsdblOnLgTDjA==/com.extreamsd.aemobile--o34yNaqcH60uit7xcWmfA==/lib/arm64/libaeoboe.so (oboe::AudioStreamAAudio::callOnAudioReady(AAudioStreamStruct, void, int)+40)

15 pc 0000000000022a4c /system/lib64/libaaudio_internal.so (aaudio::AudioStream::maybeCallDataCallback(void*, int)+192)

16 pc 0000000000024aa4 /system/lib64/libaaudio_internal.so (aaudio::AudioStreamLegacy::callDataCallbackFrames(unsigned char*, int)+304)

17 pc 00000000000251a0 /system/lib64/libaaudio_internal.so (aaudio::AudioStreamLegacy::processCallbackCommon(int, void*)+944)

18 pc 000000000008bee8 /system/lib64/libaudioclient.so (android::AudioTrack::processAudioBuffer()+2824)

19 pc 000000000008b0d8 /system/lib64/libaudioclient.so (android::AudioTrack::AudioTrackThread::threadLoop()+272)

20 pc 00000000000154d4 /system/lib64/libutils.so (android::Thread::_threadLoop(void*)+216)

21 pc 00000000000a4974 /system/lib64/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+144)

22 pc 0000000000014db0 /system/lib64/libutils.so (thread_data_t::trampoline(thread_data_t const*)+408)

23 pc 00000000000f41b8 /apex/com.android.runtime/lib64/bionic/libc.so (__pthread_start(void*)+64)

24 pc 000000000008ede4 /apex/com.android.runtime/lib64/bionic/libc.so (__start_thread+64)

Even though there is no further contextual information, perhaps it's important to know about these crashes anyway in case you see more frequent crashes in getBestTimestamp().

robertwu1 commented 2 years ago

See https://developer.android.com/ndk/guides/audio/aaudio/aaudio#thread-safety

AAudio is not completely thread safe. Oboe is a wrapper on AAudio so this issue is likely to also happen for Oboe.

philburk commented 2 years ago

@extreamsd - was the crash from an assert() or something like a SIGSEGV?

The crash is happening during a legacy callback. https://github.com/google/oboe/issues/17 pc 00000000000251a0 /system/lib64/libaaudio_internal.so (aaudio::AudioStreamLegacy::processCallbackCommon(int, void*)+944)

The callback is calling calculateLatencyMillis() while calls getTimestamp().

There were known issues with calling getTimestamp() from a legacy callback: https://github.com/google/oboe/wiki/TechNote_ReleaseBuffer

The original assert was fixed in R and the user was running R. Also the stack does not match the old bug. But it may be related.

Because of these issues, we recommend NOT calling getTimestamp or calculateLatencyMillis() from a callback. Because audio output is stable, you only need to call it once from the app once the stream is running and the results should remain valid.

I just noticed that our autodocs do not mention that recommendation. I added #1499

philburk commented 1 year ago

We are tracking this internally at b/275752736 | P4 | possible race in AudioStreamLegacy::getBestTimestamp()

tituschu0628 commented 1 year ago

hello!

i think i'm encountering almost the same error on my side! however i'm using the juce framework (also oboe 1.6.1) so my stack looks a little different.

Screenshot 2023-07-10 at 11 42 32 AM copy Screenshot 2023-07-10 at 11 42 32 AM copy 2

i did notice theres a bug fix in 1.7.0, but i wasn't sure if it was related...

if it is, then i'm kind of in an awkward situation here because i'm not using this repo directly (the files juce included doesn't look entirely the same either) so even if i wanted to bump 1.7.0 i wouldn't know exactly how to upgrade.

but since @philburk commented here after 1.7.0 release then i assume this is still a work in progress?

is there anything I can do in the code? Juce forum haven't replied my issue...

philburk commented 1 year ago

This might be related to not using std:shared_ptr when opening the stream. We need to contact JUCE folks to make sure they are using the latest recommendations.

arieshfut commented 9 months ago

hello, i think i'm encountering almost the same error on my side!

the code like this implementation 'com.google.oboe:oboe:1.7.0' std::shared_ptr<oboe::AudioStream> mAudioStream;

void AudioStreamerPlayer::initStream(int channelCount, int frequency, int deviceId) {
        // open stream
        oboe::AudioStreamBuilder builder;
        result = builder.setDirection(oboe::Direction::Output)
                ->setSharingMode(oboe::SharingMode::Shared)
                ->setPerformanceMode(oboe::PerformanceMode::LowLatency)
                ->setDeviceId(mDeviceId)
                ->setFormat(oboe::AudioFormat::I16)
                ->setSampleRate(frequency)
                ->setChannelCount(channelCount)
                ->setDataCallback(this)
                ->openStream(mAudioStream);
        if (result == oboe::Result::OK) {
            auto state = mAudioStream->setBufferSizeInFrames(2 * mAudioStream->getFramesPerBurst());
            if (state) {
                LOGD("AudioStreamerPlayer", "AudioStreamerPlayer change buffer size to %d", state.value());
            } else {
                LOGE("AudioStreamerPlayer", "buffer size could not be changed  %d", state.error());
            }

            result = mAudioStream->requestStart();
            if (result != oboe::Result::OK) {
                LOGE("Error starting playback stream. Error: %s", oboe::convertToText(result));
                mAudioStream->close();
                mAudioStream.reset();
            } else {
                isPlaying = true;
            }
        }
}
unsigned int AudioStreamerPlayer::getLatency() {
    std::lock_guard<std::mutex> lock(mLock);
    if (mAudioStream && isPlaying) {
        oboe::ResultWithValue<double> latencyResult = mAudioStream->calculateLatencyMillis();
        if (latencyResult) {
            return static_cast<unsigned int> (latencyResult.value() + 0.5);
        }
    }
    // if can not query latency, use 50; Need to find another way to handle this
    return DEFAULT_LATENCY_TIME;
}

I have encountered this problem twice already while do stress testing for app. The tombstone file like this AudioStreamerPlayer::getLatency() --> mAudioStream->calculateLatencyMillis() --> AudioStreamAAudio::getTimestamp -->AudioStreamTrack::getTimestamp-->AudioStreamLegacy::getBestTimestamp ExtendedTimestamp(crash)


Tombstone maker: 'xCrash 3.1.0' Crash type: 'native' Start time: '2023-12-06T19:00:56.441+0800' Crash time: '2023-12-07T07:59:43.018+0800' App ID: 'com.cmcc.sc.app' App version: '1.0.0.3.7bff47fb.1206' Rooted: 'Yes' API level: '30' OS version: '11' Kernel version: 'Linux version 4.19.219 #256 SMP PREEMPT Tue Feb 21 16:50:00 CST 2023 (aarch64)' ABI list: 'arm64-v8a,armeabi-v7a,armeabi' Manufacturer: 'Centerm' Brand: 'Centerm' Model: 'VAR211' Build fingerprint: 'Centerm/rk356x_box/rk356x_box:11/RQ3A.210705.001/V8.30.06:userdebug/release-keys' ABI: 'arm64' pid: 20711, tid: 25546, name: pool-11-thread- >>> com.cmcc.sc.app <<< signal 6 (SIGABRT), code -1 (SI_QUEUE), fault addr -------- x0 0000000000000000 x1 00000000000063ca x2 0000000000000006 x3 00000078c4f14f60 x4 0000000029aaaaf1 x5 0000000029aaaaf1 x6 0000000029aaaaf1 x7 0000007bc8865010 x8 00000000000000f0 x9 0000007bc20b67c0 x10 ffffff80fffffbdf x11 0000000000000001 x12 0000000000000000 x13 00000078c42d3040 x14 0000000000888904 x15 0000000000000000 x16 0000007bc214ec80 x17 0000007bc2130320 x18 0000000000000000 x19 00000000000050e7 x20 00000000000063ca x21 00000000ffffffff x22 0000000000000001 x23 0000007929d09d70 x24 00000078c4f17000 x25 0000000000000000 x26 0000000000000041 x27 0000000000000041 x28 00000078701e7b88 x29 00000078c4f14fe0 sp 00000078c4f14f40 lr 0000007bc20e4148 pc 0000007bc20e4178

backtrace:

00 pc 000000000004e178 /apex/com.android.runtime/lib64/bionic/libc.so (abort+168)

#01 pc 00000000000258d0  /system/lib64/libaaudio_internal.so (_ZN6aaudio17AudioStreamLegacy16getBestTimestampEiPlS1_PN7android17ExtendedTimestampE+352)
#02 pc 00000000000293f8  /system/lib64/libaaudio_internal.so (_ZN6aaudio16AudioStreamTrack12getTimestampEiPlS1_+220)
#03 pc 0000000000028548  /data/app/~~QziJkTG8praoUPGnGlAGqQ==/com.cmcc.sc.app-iHwinl9OvCedWjV9qK6CkQ==/lib/arm64/liboboe.so (_ZN4oboe17AudioStreamAAudio12getTimestampEiPlS1_+108)
#04 pc 00000000000285d8  /data/app/~~QziJkTG8praoUPGnGlAGqQ==/com.cmcc.sc.app-iHwinl9OvCedWjV9qK6CkQ==/lib/arm64/liboboe.so (_ZN4oboe17AudioStreamAAudio22calculateLatencyMillisEv+60)
#05 pc 000000000062b1a0  /data/app/~~QziJkTG8praoUPGnGlAGqQ==/com.cmcc.sc.app-iHwinl9OvCedWjV9qK6CkQ==/lib/arm64/libcmccspice.so (_ZN19AudioStreamerPlayer10getLatencyEv+168)
#06 pc 000000000062da60  /data/app/~~QziJkTG8praoUPGnGlAGqQ==/com.cmcc.sc.app-iHwinl9OvCedWjV9qK6CkQ==/lib/arm64/libcmccspice.so (getLatency+44)

in order to keep audio and picture synchronizing, i will call AudioStreamerPlayer::getLatency() once a second. The crash is happed when stream just started, and do not known how to reproduce or trigger it.

@philburk from the backtrace i can not find why it will crash on ExtendedTimestamp or getBestTimestamp, is there anything I can do in the code to avoid the crash?

philburk commented 9 months ago

@arieshfut - I cannot match this to any known bug.

Is it happening on any release other than R?

Does it seem to happen when plugging or unplugging a headset, or connecting or disconnecting Bluetooth?

Does it still happen with Oboe 1.8.0?

Can you reproduce it reliably? If so then please provide repro steps.

arieshfut commented 9 months ago

Is it happening on any release other than R? ---- I only have two types of devices android 9 and android 11, and only find on android R version.

Does it seem to happen when plugging or unplugging a headset, or connecting or disconnecting Bluetooth? ---- plug headset first, and then start play video by oboe.

Does it still happen with Oboe 1.8.0? ---- this crash only happed twice. when i try oboe 1.8 can not reproduce it.

Can you reproduce it reliably? If so then please provide repro steps. ---- can not reproduce reliably. Afterwards, I will continue to observe and test

now i am trying to call getLatency function separate from audio stream callback, expect can fix this bug. @philburk thank you very much for your reply. I will do more testing and verification in the future. I also look forward to your new discoveries on this crash and reply to messages. Thank you again.

KaboXue commented 1 month ago

@philburk Hello, two years have passed, I wonder if this problem has been solved, our project also has this function crash, adb logcat log is as follows:

08-15 08:19:20.198 12284 12284 F crashpad: O{;+1qpOl-$4ZjPE.OS5Wm{H[sdzXC5b|u7IyP^LZpF)>xr5WmNqe)RbkgRY+J+^k)Ds'DX2As;>OZwm@f;"^F>nr)npBsmw>xs[TL! 08-15 08:19:20.198 12284 12284 F crashpad: -----END CRASHPAD MINIDUMP----- 08-15 08:19:21.019 3184 8552 F libc : Fatal signal 6 (SIGABRT), code -6 (SI_TKILL) in tid 8552 (AudioTrack), pid 3184 (com.xzjhm.gwaz) 08-15 08:19:21.172 12301 12301 F DEBUG : 08-15 08:19:21.172 12301 12301 F DEBUG : Build fingerprint: 'OnePlus/OnePlus8Pro/OnePlus8Pro:12/V417IR/2406071527:user/release-keys' 08-15 08:19:21.172 12301 12301 F DEBUG : Revision: '0' 08-15 08:19:21.172 12301 12301 F DEBUG : ABI: 'x86' 08-15 08:19:21.172 12301 12301 F DEBUG : Timestamp: 2024-08-15 08:19:21.057400673+0800 08-15 08:19:21.172 12301 12301 F DEBUG : Process uptime: 44739s 08-15 08:19:21.172 12301 12301 F DEBUG : Cmdline: com.xzjhm.gwaz 08-15 08:19:21.172 12301 12301 F DEBUG : pid: 3184, tid: 8552, name: AudioTrack >>> com.xzjhm.gwaz <<< 08-15 08:19:21.172 12301 12301 F DEBUG : uid: 10096 08-15 08:19:21.172 12301 12301 F DEBUG : signal 6 (SIGABRT), code -6 (SI_TKILL), fault addr -------- 08-15 08:19:21.172 12301 12301 F DEBUG : eax 00000000 ebx 00000c70 ecx 00002168 edx 00000006 08-15 08:19:21.172 12301 12301 F DEBUG : edi e8f7055e esi b9dd6a80 08-15 08:19:21.172 12301 12301 F DEBUG : ebp ed5f7db0 esp b9dd6a28 eip ed5f7db9 08-15 08:19:21.172 12301 12301 F DEBUG : backtrace: 08-15 08:19:21.172 12301 12301 F DEBUG : #00 pc 00000db9 [vdso] (__kernel_vsyscall+9) 08-15 08:19:21.172 12301 12301 F DEBUG : #01 pc 0005e048 /apex/com.android.runtime/lib/bionic/libc.so (syscall+40) (BuildId: c8e77979bced6996f98ee4cc0489debe) 08-15 08:19:21.172 12301 12301 F DEBUG : #02 pc 0007ae31 /apex/com.android.runtime/lib/bionic/libc.so (abort+209) (BuildId: c8e77979bced6996f98ee4cc0489debe) 08-15 08:19:21.172 12301 12301 F DEBUG : #03 pc 0001eed0 /system/lib/libaaudio_internal.so (aaudio::AudioStreamLegacy::getBestTimestamp(int, long long, long long, android::ExtendedTimestamp)+336) (BuildId: 5ce3aaa2e127ede2cdeaeba8054f0c06) 08-15 08:19:21.172 12301 12301 F DEBUG : #04 pc 00022ec1 /system/lib/libaaudio_internal.so (aaudio::AudioStreamTrack::getTimestamp(int, long long, long long*)+225) (BuildId: 5ce3aaa2e127ede2cdeaeba8054f0c06) 08-15 08:19:21.172 12301 12301 F DEBUG : #05 pc 00004778 /system/lib/libaaudio.so (AAudioStream_getTimestamp+72) (BuildId: f0c8441a1dd65dc22bf55fdee4541ca5) 08-15 08:19:21.172 12301 12301 F DEBUG : #06 pc 0276d9aa /system/product/app/webview/webview.apk!libwebviewchromium.so (BuildId: c2d210540cb8407c13ed243d4572b9e8187fddc1) 08-15 08:19:21.184 1208 12306 I DropBoxManagerService: add tag=data_app_native_crash isTagEnabled=true flags=0x2 08-15 08:19:21.184 1208 1285 I BootReceiver: Copying /data/tombstones/tombstone_13 to DropBox (SYSTEM_TOMBSTONE) 08-15 08:19:21.184 1208 1285 I DropBoxManagerService: add tag=SYSTEM_TOMBSTONE isTagEnabled=true flags=0x6

The running environment is mumu emulator, Android kernel 12 version, long time (more than 12 hours) continuous playback of audio will appear this problem. The results obtained in connection with the simulator technology are as follows:

微信图片_20240815155639