Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Android][AAudio] Crash occurs when creating and running a stream the second time. #466

Closed
kblinichkin opened this issue May 10, 2022 · 5 comments

Comments

@kblinichkin
Copy link

I've caught a crash while was testing my application with google test framework. The same happened when I just substituted my code with the Simple Playback sample. The resulted code consists of 2 tests each of which contains the duplicate of the Simple Playback sample code. As soon as the first test passed, the crash occurs as a result of running the second one after calling ma_device_start function. The callback works for awhile and then crashes.

As an attempt to find out what happened I tried to remove ma_device_uninit function from the first test and the second test with the application code didn't crash again. However the same doesn't work with samples.
It looks like there is a problem with ma_device_uninit function which doesn't perform full cleanup.

It's not an issue with AAudio itself because I use Oboe Library with the same application and it works well.

Steps to reproduce:
Precondition: not empty WAV file.

  1. Launch 2 samples of the Simple Playback one after another in a single instance of application.
  2. Observe the crash.

OS: Android 11 (AAudio)
HW: both Emulator (x86_64) and Device (aarmv8)
Occurence: 100%

Full log:

05-10 15:43:13.933 8454 8478 D com.garmony_o.tests.unittestrunner.MainActivity: [ RUN ] AudioOutTest.MA_SAMPLE_1
05-10 15:43:13.941 8482 8482 I AAudio : AAudioStreamBuilder_openStream() called ----------------------------------------
05-10 15:43:13.942 8482 8482 I AudioStreamBuilder: rate = 22050, channels = 1, format = 1, sharing = SH, dir = OUTPUT
05-10 15:43:13.942 8482 8482 I AudioStreamBuilder: device = 0, sessionId = -1, perfMode = 12, callback: ON with frames = 220
05-10 15:43:13.942 8482 8482 I AudioStreamBuilder: usage = 0, contentType = 0, inputPreset = 0, allowedCapturePolicy = 0
05-10 15:43:13.942 8482 8482 I AudioStreamBuilder: privacy sensitive = false
05-10 15:43:13.942 8482 8482 D testGarmony_o: PlayerBase::PlayerBase()
05-10 15:43:13.922 8482 8482 W Thread-2: type=1400 audit(0.0:188): avc: granted { execute } for name="testGarmony_o" dev="dm-5" ino=131088 scontext=u:r:untrusted_app_27:s0:c131,c256,c512,c768 tcontext=u:object_r:app_data_file:s0:c131,c256,c512,c768 tclass=file app=com.garmony_o.tests.unittestrunner
05-10 15:43:13.944 8482 8482 D AudioStreamTrack: open(), request notificationFrames = 220, frameCount = 660
05-10 15:43:13.952 507 2368 I system_server: oneway function results will be dropped but finished with status OK and parcel size 4
05-10 15:43:13.952 507 2368 I chatty : uid=1000(system) Binder:507_13 identical 2 lines
05-10 15:43:13.952 507 2368 I system_server: oneway function results will be dropped but finished with status OK and parcel size 4
05-10 15:43:13.926 8482 8482 W Thread-2: type=1400 audit(0.0:189): avc: granted { execute_no_trans } for path="/data/user/0/com.garmony_o.tests.unittestrunner/files/testGarmony_o" dev="dm-5" ino=131088 scontext=u:r:untrusted_app_27:s0:c131,c256,c512,c768 tcontext=u:object_r:app_data_file:s0:c131,c256,c512,c768 tclass=file app=com.garmony_o.tests.unittestrunner
05-10 15:43:13.957 370 455 W AudioFlinger: createTrack_l(): mismatch between requested flags (00000104) and output flags (00000002)
05-10 15:43:13.926 8482 8482 W testGarmony_o: type=1400 audit(0.0:190): avc: granted { execute } for path="/data/user/0/com.garmony_o.tests.unittestrunner/files/testGarmony_o" dev="dm-5" ino=131088 scontext=u:r:untrusted_app_27:s0:c131,c256,c512,c768 tcontext=u:object_r:app_data_file:s0:c131,c256,c512,c768 tclass=file app=com.garmony_o.tests.unittestrunner
05-10 15:43:13.969 370 455 D AF::TrackHandle: OpPlayAudio: track:181 usage:1 not muted
05-10 15:43:13.972 8482 8482 D AudioTrack: createTrack_l(0): AUDIO_OUTPUT_FLAG_FAST denied by server; frameCount 660 -> 984
05-10 15:43:13.975 8482 8482 D AAudioStream: setState(s#1) from 0 to 2
05-10 15:43:13.976 8482 8482 W AudioStreamTrack: open() flags changed from 0x00000104 to 0x00000000
05-10 15:43:13.976 8482 8482 W AudioStreamTrack: open() perfMode changed from 12 to 10
05-10 15:43:13.977 8482 8482 I AAudio : AAudioStreamBuilder_openStream() returns 0 = AAUDIO_OK for s#1 ----------------
05-10 15:43:13.977 8482 8482 D AAudio : AAudioStream_requestStart(s#1) called --------------
05-10 15:43:13.977 8482 8482 D AAudioStream: setState(s#1) from 2 to 3
05-10 15:43:13.978 370 455 W APM::AudioPolicyEngine: getDevicesForStrategy() unknown strategy: -1
05-10 15:43:13.978 370 455 W APM::AudioPolicyEngine: getDevicesForStrategy() unknown strategy: -1
05-10 15:43:13.979 8482 8482 D testGarmony_o: PlayerBase::start() from IPlayer
05-10 15:43:13.979 8482 8482 D AAudio : AAudioStream_requestStart(s#1) returned 0 ---------
05-10 15:43:13.980 507 2943 I system_server: oneway function results will be dropped but finished with status OK and parcel size 4
05-10 15:43:13.980 8482 8488 D AudioStreamLegacy: onAudioDeviceUpdate() devId 2 => 2
05-10 15:43:13.987 8482 8485 D AAudioStream: setState(s#1) from 3 to 4
05-10 15:43:14.039 370 457 D AudioFlinger: mixer(0x75dfdd75a040) throttle end: throttle time(9)
05-10 15:43:14.914 507 1285 E TaskPersister: File error accessing recents directory (directory doesn't exist?).
05-10 15:43:16.937 2551 2551 I perfetto: probes_producer.cc:329 Producer stop (id=62)
05-10 15:43:16.941 2551 2551 I perfetto: ftrace_procfs.cc:183 disabled ftrace
05-10 15:43:16.942 412 412 I perfetto: ng_service_impl.cc:1948 Tracing session 62 ended, total sessions:0
05-10 15:43:16.929 0 0 W perfetto: disabled ftrace
05-10 15:43:16.955 507 2680 I system_server: oneway function results will be dropped but finished with status OK and parcel size 4
05-10 15:43:19.003 8482 8482 D AAudio : AAudioStream_requestStop(s#1) called
05-10 15:43:19.003 8482 8482 D AAudioStream: setState(s#1) from 4 to 9
05-10 15:43:19.003 8482 8482 D AudioTrack: stop(176): called with 112200 frames delivered
05-10 15:43:19.004 8482 8482 D testGarmony_o: PlayerBase::stop() from IPlayer
05-10 15:43:19.004 8482 8482 D AAudioStream: setState(s#1) from 9 to 10
05-10 15:43:19.004 8482 8482 D AAudio : AAudioStream_close(s#1) called ---------------
05-10 15:43:19.004 8482 8482 D AAudioStream: setState(s#1) from 10 to 11
05-10 15:43:19.004 8482 8482 D AAudioStream: setState(s#1) from 11 to 12
05-10 15:43:19.010 8482 8482 D AAudio : AAudioStream_close(s#1) returned 0 ---------
05-10 15:43:19.012 8482 8482 I BpBinder: onLastStrongRef automatically unlinking death recipients:
05-10 15:43:19.012 8482 8482 I chatty : uid=10131(com.garmony_o.tests.unittestrunner) /data/user/0/com.garmony_o.tests.unittestrunner/files/testGarmony_o identical 1 line
05-10 15:43:19.012 8482 8482 I BpBinder: onLastStrongRef automatically unlinking death recipients:
05-10 15:43:19.014 8454 8478 D com.garmony_o.tests.unittestrunner.MainActivity: [ OK ] AudioOutTest.MA_SAMPLE_1 (5081 ms)
05-10 15:43:19.014 8454 8478 D com.garmony_o.tests.unittestrunner.MainActivity: [ RUN ] AudioOutTest.MA_SAMPLE_2
05-10 15:43:19.022 8482 8482 I AAudio : AAudioStreamBuilder_openStream() called ----------------------------------------
05-10 15:43:19.022 8482 8482 I AudioStreamBuilder: rate = 22050, channels = 1, format = 1, sharing = SH, dir = OUTPUT
05-10 15:43:19.022 8482 8482 I AudioStreamBuilder: device = 0, sessionId = -1, perfMode = 12, callback: ON with frames = 220
05-10 15:43:19.022 8482 8482 I AudioStreamBuilder: usage = 0, contentType = 0, inputPreset = 0, allowedCapturePolicy = 0
05-10 15:43:19.022 8482 8482 I AudioStreamBuilder: privacy sensitive = false
05-10 15:43:19.022 8482 8482 D testGarmony_o: PlayerBase::PlayerBase()
05-10 15:43:19.023 8482 8482 D AudioStreamTrack: open(), request notificationFrames = 220, frameCount = 660
--------- beginning of crash
05-10 15:43:19.026 8482 8488 F libc : Fatal signal 11 (SIGSEGV), code 2 (SEGV_ACCERR), fault addr 0x76b698399e10 in tid 8488 (Binder:8482_2), pid 8482 (testGarmony_o)
05-10 15:43:19.027 507 2943 I system_server: oneway function results will be dropped but finished with status OK and parcel size 4
05-10 15:43:19.027 507 2943 I system_server: oneway function results will be dropped but finished with status OK and parcel size 4
05-10 15:43:19.029 370 828 W AudioFlinger: createTrack_l(): mismatch between requested flags (00000104) and output flags (00000002)
05-10 15:43:19.034 370 828 D AF::TrackHandle: OpPlayAudio: track:182 usage:1 not muted
05-10 15:43:19.036 8482 8482 D AudioTrack: createTrack_l(176): AUDIO_OUTPUT_FLAG_FAST denied by server; frameCount 660 -> 984
05-10 15:43:19.038 8482 8482 D AAudioStream: setState(s#1) from 0 to 2
05-10 15:43:19.039 370 445 W APM::AudioPolicyEngine: getDevicesForStrategy() unknown strategy: -1
05-10 15:43:19.039 370 445 W APM::AudioPolicyEngine: getDevicesForStrategy() unknown strategy: -1
05-10 15:43:19.041 507 2943 I system_server: oneway function results will be dropped but finished with status OK and parcel size 4
05-10 15:43:19.045 8482 8482 W AudioStreamTrack: open() flags changed from 0x00000104 to 0x00000000
05-10 15:43:19.045 8482 8482 W AudioStreamTrack: open() perfMode changed from 12 to 10
05-10 15:43:19.049 8482 8482 I AAudio : AAudioStreamBuilder_openStream() returns 0 = AAUDIO_OK for s#1 ----------------
05-10 15:43:19.050 8482 8482 D AAudio : AAudioStream_requestStart(s#1) called --------------
05-10 15:43:19.050 8482 8482 D AAudioStream: setState(s#1) from 2 to 3
05-10 15:43:19.051 370 828 W APM::AudioPolicyEngine: getDevicesForStrategy() unknown strategy: -1
05-10 15:43:19.051 370 828 W APM::AudioPolicyEngine: getDevicesForStrategy() unknown strategy: -1
05-10 15:43:19.051 8482 8482 D testGarmony_o: PlayerBase::start() from IPlayer
05-10 15:43:19.052 8482 8482 D AAudio : AAudioStream_requestStart(s#1) returned 0 ---------
05-10 15:43:19.061 8482 8490 D AAudioStream: setState(s#1) from 3 to 4
05-10 15:43:19.061 507 2680 I system_server: oneway function results will be dropped but finished with status OK and parcel size 4
05-10 15:43:19.075 8495 8495 I crash_dump64: obtaining output fd from tombstoned, type: kDebuggerdTombstone
05-10 15:43:19.077 264 264 I tombstoned: received crash request for pid 8488
05-10 15:43:19.079 8495 8495 I crash_dump64: performing dump of process 8482 (target tid = 8488)
05-10 15:43:19.085 8495 8495 F DEBUG : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
05-10 15:43:19.085 8495 8495 F DEBUG : Build fingerprint: 'Android/sdk_phone_x86_64/generic_x86_64:11/RSR1.210722.012/7758210:userdebug/test-keys'
05-10 15:43:19.085 8495 8495 F DEBUG : Revision: '0'
05-10 15:43:19.085 8495 8495 F DEBUG : ABI: 'x86_64'
05-10 15:43:19.087 8495 8495 F DEBUG : Timestamp: 2022-05-10 15:43:19+0700
05-10 15:43:19.088 8495 8495 F DEBUG : pid: 8482, tid: 8488, name: Binder:8482_2 >>> /data/user/0/com.garmony_o.tests.unittestrunner/files/testGarmony_o <<<
05-10 15:43:19.088 8495 8495 F DEBUG : uid: 10131
05-10 15:43:19.088 8495 8495 F DEBUG : signal 11 (SIGSEGV), code 2 (SEGV_ACCERR), fault addr 0x76b698399e10
05-10 15:43:19.088 8495 8495 F DEBUG : rax 0000000000000000 rbx 0000000000000100 rcx 6f1ff8da08198821 rdx 000076b697f43b30
05-10 15:43:19.088 8495 8495 F DEBUG : r8 0000000000000000 r9 0000000000000000 r10 0000000000000000 r11 0000000000000206
05-10 15:43:19.088 8495 8495 F DEBUG : r12 000076b7f8de7130 r13 000076b697f43b30 r14 000076b7f8de71d8 r15 000076b7f8de7250
05-10 15:43:19.088 8495 8495 F DEBUG : rdi 0000000000000005 rsi 00000000c0306201
05-10 15:43:19.089 8495 8495 F DEBUG : rbp 00000000fffffff7 rsp 000076b697f43b10 rip 000076b698399e10
05-10 15:43:19.089 8495 8495 F DEBUG : backtrace:
05-10 15:43:19.089 8495 8495 F DEBUG : #00 pc 000000000000ee10 /system/lib64/libaudioutils.so (BuildId: dc8b91cfb333c513abb18860cb60f824)
05-10 15:43:19.107 0 0 D logd : logdr: UID=10131 GID=10131 PID=8495 n tail=50 logMask=8 pid=8482 start=0ns timeout=0ns
05-10 15:43:19.111 0 0 D logd : logdr: UID=10131 GID=10131 PID=8495 n tail=50 logMask=1 pid=8482 start=0ns timeout=0ns
05-10 15:43:19.149 0 0 D logd : logdr: UID=10131 GID=10131 PID=8495 n tail=0 logMask=8 pid=8482 start=0ns timeout=0ns
05-10 15:43:19.151 0 0 D logd : logdr: UID=10131 GID=10131 PID=8495 n tail=0 logMask=1 pid=8482 start=0ns timeout=0ns
05-10 15:43:19.166 507 695 W NativeCrashListener: Couldn't find ProcessRecord for pid 8482
05-10 15:43:19.166 264 264 E tombstoned: Tombstone written to: /data/tombstones/tombstone_04
05-10 15:43:19.170 507 545 I BootReceiver: Copying /data/tombstones/tombstone_04 to DropBox (SYSTEM_TOMBSTONE)
05-10 15:43:19.171 507 545 I DropBoxManagerService: add tag=SYSTEM_TOMBSTONE isTagEnabled=true flags=0x2
05-10 15:43:19.194 8454 8478 D com.garmony_o.tests.unittestrunner.MainActivity: Finished executing binary
05-10 15:43:19.180 0 0 I init : Untracked pid 8495 exited with status 0
05-10 15:43:19.185 0 0 I binder : undelivered transaction 997114, process died.
05-10 15:43:19.186 0 0 I binder : undelivered transaction 997174, process died.
05-10 15:43:19.190 0 0 I binder : undelivered transaction 997182, process died.
05-10 15:43:19.195 0 0 I init : Untracked pid 8497 exited with status 0
05-10 15:43:19.199 0 0 I binder : undelivered transaction 997193, process died.
05-10 15:43:19.241 507 2680 I system_server: oneway function results will be dropped but finished with status OK and parcel size 4
05-10 15:43:19.241 370 445 W APM::AudioPolicyEngine: getDevicesForStrategy() unknown strategy: -1
05-10 15:43:19.241 370 445 W APM::AudioPolicyEngine: getDevicesForStrategy() unknown strategy: -1
05-10 15:43:22.040 507 2943 I system_server: oneway function results will be dropped but finished with status OK and parcel size 4

@kblinichkin kblinichkin changed the title Crash when creating and running a stream second time. [Android][AAudio] Crash when creating and running a stream the second time. May 10, 2022
@kblinichkin kblinichkin changed the title [Android][AAudio] Crash when creating and running a stream the second time. [Android][AAudio] Crash occurs when creating and running a stream the second time. May 10, 2022
@mackron
Copy link
Owner

mackron commented May 10, 2022

Thanks for the report. Are you able to post the exact Simple Playback example code? Is it basically just the code below? Also, are you able to force the OpenSL backend just so I can see if it's a more general miniaudio problem or if it's specific to the AAudio backend (#define MA_NO_AAUDIO)?

#define MINIAUDIO_IMPLEMENTATION
#include "../miniaudio.h"

#include <stdio.h>

void data_callback(ma_device* pDevice, void* pOutput, const void* pInput, ma_uint32 frameCount)
{
    ma_decoder* pDecoder = (ma_decoder*)pDevice->pUserData;
    if (pDecoder == NULL) {
        return;
    }

    ma_decoder_read_pcm_frames(pDecoder, pOutput, frameCount, NULL);

    (void)pInput;
}

int run(int argc, char** argv)
{
	ma_result result;
	ma_decoder decoder;
	ma_device_config deviceConfig;
	ma_device device;

	if (argc < 2) {
		printf("No input file.\n");
		return -1;
	}

	result = ma_decoder_init_file(argv[1], NULL, &decoder);
	if (result != MA_SUCCESS) {
		printf("Could not load file: %s\n", argv[1]);
		return -2;
	}

	deviceConfig = ma_device_config_init(ma_device_type_playback);
	deviceConfig.playback.format   = decoder.outputFormat;
	deviceConfig.playback.channels = decoder.outputChannels;
	deviceConfig.sampleRate        = decoder.outputSampleRate;
	deviceConfig.dataCallback      = data_callback;
	deviceConfig.pUserData         = &decoder;

	if (ma_device_init(NULL, &deviceConfig, &device) != MA_SUCCESS) {
		printf("Failed to open playback device.\n");
		ma_decoder_uninit(&decoder);
		return -3;
	}

	if (ma_device_start(&device) != MA_SUCCESS) {
		printf("Failed to start playback device.\n");
		ma_device_uninit(&device);
		ma_decoder_uninit(&decoder);
		return -4;
	}

	printf("Press Enter to quit...");
	getchar();

	ma_device_uninit(&device);
	ma_decoder_uninit(&decoder);

	return 0;
}

int main(int argc, char** argv)
{
	int i;
	for (i = 0; i < 2; i += 1) {
		int result = run(argc, argv);
		if (result != 0) {
			return result;
		}
	}

    return 0;
}

It's surprising to me that it runs for a while before crashing. Just looking at the code, the teardown for AAudio looks fairly simple to me. I'll have a look at how Oboe does it's teardown when I get a chance.

@kblinichkin
Copy link
Author

Hi!

Sorry for the delay.

Are you able to post the exact Simple Playback example code?

//...
// Some includes and other uninteresting stuff above.
//...
void data_callback(ma_device* pDevice, void* pOutput, const void* pInput, ma_uint32 frameCount)
{
    ma_decoder* pDecoder = (ma_decoder*)pDevice->pUserData;
    if (pDecoder == NULL) {
        return;
    }

    ma_decoder_read_pcm_frames(pDecoder, pOutput, frameCount, NULL);

    (void)pInput;
}

TEST_F(AudioOutTest, MA_SAMPLE_1) {
    ma_result result;
    ma_decoder decoder;
    ma_device_config deviceConfig;
    ma_device device;

    result = ma_decoder_init_file((APP_FILES_PATH + TEST_AUDIO_WAV_FILEANAME).c_str(), NULL, &decoder);
    if (result != MA_SUCCESS) {
        printf("Could not load file: %s\n", (APP_FILES_PATH + TEST_AUDIO_WAV_FILEANAME).c_str());
        ASSERT_EQ(false, false);
    }

    deviceConfig = ma_device_config_init(ma_device_type_playback);
    deviceConfig.playback.format   = decoder.outputFormat;
    deviceConfig.playback.channels = decoder.outputChannels;
    deviceConfig.sampleRate        = decoder.outputSampleRate;
    deviceConfig.dataCallback      = data_callback;
    deviceConfig.pUserData         = &decoder;

    if (ma_device_init(NULL, &deviceConfig, &device) != MA_SUCCESS) {
        printf("Failed to open playback device.\n");
        ma_decoder_uninit(&decoder);
        ASSERT_EQ(false, false);
    }

    if (ma_device_start(&device) != MA_SUCCESS) {
        printf("Failed to start playback device.\n");
        ma_device_uninit(&device);
        ma_decoder_uninit(&decoder);
        ASSERT_EQ(false, false);
    }

    using namespace std::chrono_literals;
    std::this_thread::sleep_for(5s);

    ma_device_uninit(&device);
    ma_decoder_uninit(&decoder);
}

TEST_F(AudioOutTest, MA_SAMPLE_2) {
    ma_result result;
    ma_decoder decoder;
    ma_device_config deviceConfig;
    ma_device device;

    result = ma_decoder_init_file((APP_FILES_PATH + TEST_AUDIO_WAV_FILEANAME).c_str(), NULL, &decoder);
    if (result != MA_SUCCESS) {
        printf("Could not load file: %s\n", (APP_FILES_PATH + TEST_AUDIO_WAV_FILEANAME).c_str());
        ASSERT_EQ(false, false);
    }

    deviceConfig = ma_device_config_init(ma_device_type_playback);
    deviceConfig.playback.format   = decoder.outputFormat;
    deviceConfig.playback.channels = decoder.outputChannels;
    deviceConfig.sampleRate        = decoder.outputSampleRate;
    deviceConfig.dataCallback      = data_callback;
    deviceConfig.pUserData         = &decoder;

    if (ma_device_init(NULL, &deviceConfig, &device) != MA_SUCCESS) {
        printf("Failed to open playback device.\n");
        ma_decoder_uninit(&decoder);
        ASSERT_EQ(false, false);
    }

    if (ma_device_start(&device) != MA_SUCCESS) {
        printf("Failed to start playback device.\n");
        ma_device_uninit(&device);
        ma_decoder_uninit(&decoder);
        ASSERT_EQ(false, false);
    }

    using namespace std::chrono_literals;
    std::this_thread::sleep_for(5s);

    ma_device_uninit(&device);
    ma_decoder_uninit(&decoder);
}
// End of file.

Also, are you able to force the OpenSL backend

I checked with OpenSL only, both tests passed and no crash was observed. It seems like it's the issue only with AAudio.
Please, check the logs below:

05-13 01:01:15.409 8304 8328 D com.garmony_o.tests.unittestrunner.MainActivity: [ RUN ] AudioOutTest.MA_SAMPLE_1
05-13 01:01:15.397 8332 8332 W Thread-2: type=1400 audit(0.0:183): avc: granted { execute_no_trans } for path="/data/user/0/com.garmony_o.tests.unittestrunner/files/testGarmony_o" dev="dm-5" ino=131088 scontext=u:r:untrusted_app_27:s0:c131,c256,c512,c768 tcontext=u:object_r:app_data_file:s0:c131,c256,c512,c768 tclass=file app=com.garmony_o.tests.unittestrunner
05-13 01:01:15.572 507 2162 I system_server: oneway function results will be dropped but finished with status OK and parcel size 4
05-13 01:01:15.572 507 2162 I system_server: oneway function results will be dropped but finished with status OK and parcel size 4
05-13 01:01:15.572 8332 8332 D testGarmony_o: PlayerBase::PlayerBase()
05-13 01:01:15.574 507 2162 I system_server: oneway function results will be dropped but finished with status OK and parcel size 4
05-13 01:01:15.574 507 2162 I system_server: oneway function results will be dropped but finished with status OK and parcel size 4
05-13 01:01:15.574 8332 8332 D testGarmony_o: TrackPlayerBase::TrackPlayerBase()
05-13 01:01:15.574 8332 8332 I libOpenSLES: Emulating old channel mask behavior (ignoring positional mask 0x4, using default mask 0x1 based on channel count of 1)
05-13 01:01:15.578 370 2351 W AudioFlinger: createTrack_l(): mismatch between requested flags (00000104) and output flags (00000002)
05-13 01:01:15.579 370 2351 D AudioFlinger: Client defaulted notificationFrames to 441 for frameCount 984
05-13 01:01:15.581 370 2351 D AF::TrackHandle: OpPlayAudio: track:179 usage:1 not muted
05-13 01:01:15.584 8332 8332 D AudioTrack: createTrack_l(0): AUDIO_OUTPUT_FLAG_FAST denied by server; frameCount 0 -> 984
05-13 01:01:15.588 370 2351 W APM::AudioPolicyEngine: getDevicesForStrategy() unknown strategy: -1
05-13 01:01:15.588 370 2351 W APM::AudioPolicyEngine: getDevicesForStrategy() unknown strategy: -1
05-13 01:01:15.592 507 2368 I system_server: oneway function results will be dropped but finished with status OK and parcel size 4
05-13 01:01:16.765 507 1285 E TaskPersister: File error accessing recents directory (directory doesn't exist?).
05-13 01:01:18.583 507 2368 I system_server: oneway function results will be dropped but finished with status OK and parcel size 4
05-13 01:01:18.694 2551 2551 I perfetto: probes_producer.cc:329 Producer stop (id=60)
05-13 01:01:18.697 2551 2551 I perfetto: ftrace_procfs.cc:183 disabled ftrace
05-09 19:11:04.520 0 0 W perfetto: disabled ftrace
05-13 01:01:18.701 412 412 I perfetto: ng_service_impl.cc:1948 Tracing session 60 ended, total sessions:0
05-13 01:01:18.705 422 8300 I iorapd : Perfetto TraceBuffer saved to file: /data/misc/iorapd/com.garmony_o.tests.unittestrunner/1/com.garmony_o.tests.unittestrunner.MainActivity/raw_traces/1652378478705189000.perfetto_trace.pb
05-13 01:01:20.613 8332 8332 D testGarmony_o: PlayerBase::stop() from IPlayer
05-13 01:01:20.614 8332 8332 D AudioTrack: stop(174): called with 111760 frames delivered
05-13 01:01:20.617 8304 8328 D com.garmony_o.tests.unittestrunner.MainActivity: [ OK ] AudioOutTest.MA_SAMPLE_1 (5210 ms)
05-13 01:01:20.617 8304 8328 D com.garmony_o.tests.unittestrunner.MainActivity: [ RUN ] AudioOutTest.MA_SAMPLE_2
05-13 01:01:20.618 8332 8332 D testGarmony_o: PlayerBase::PlayerBase()
05-13 01:01:20.619 8332 8332 D testGarmony_o: TrackPlayerBase::TrackPlayerBase()
05-13 01:01:20.620 8332 8332 I libOpenSLES: Emulating old channel mask behavior (ignoring positional mask 0x4, using default mask 0x1 based on channel count of 1)
05-13 01:01:20.622 370 370 W AudioFlinger: createTrack_l(): mismatch between requested flags (00000104) and output flags (00000002)
05-13 01:01:20.623 370 370 D AudioFlinger: Client defaulted notificationFrames to 441 for frameCount 984
05-13 01:01:20.624 370 370 D AF::TrackHandle: OpPlayAudio: track:180 usage:1 not muted
05-13 01:01:20.627 8332 8332 D AudioTrack: createTrack_l(174): AUDIO_OUTPUT_FLAG_FAST denied by server; frameCount 0 -> 984
05-13 01:01:20.632 8332 8339 D testGarmony_o: PlayerBase::stop() from IPlayer
05-13 01:01:20.632 8332 8339 D AudioTrack: stop(175): called with 0 frames delivered
05-13 01:01:20.634 8332 8339 D testGarmony_o: PlayerBase::stop() from IPlayer
05-13 01:01:20.634 8332 8339 D AudioTrack: stop(175): called with 220 frames delivered
05-13 01:01:20.635 8332 8339 D testGarmony_o: PlayerBase::stop() from IPlayer
05-13 01:01:20.635 8332 8339 D AudioTrack: stop(175): called with 220 frames delivered
05-13 01:01:20.642 507 2368 I system_server: oneway function results will be dropped but finished with status OK and parcel size 4
05-13 01:01:25.642 8332 8339 D testGarmony_o: PlayerBase::stop() from IPlayer
05-13 01:01:25.642 8332 8339 D AudioTrack: stop(175): called with 110880 frames delivered
05-13 01:01:25.651 8332 8332 D testGarmony_o: PlayerBase::stop() from IPlayer
05-13 01:01:25.655 8304 8328 D com.garmony_o.tests.unittestrunner.MainActivity: [ OK ] AudioOutTest.MA_SAMPLE_2 (5037 ms)

@mackron
Copy link
Owner

mackron commented Oct 31, 2022

Unfortunately I've been unable to replicate this one. I'm using the "Pixel XL API 26" emulator and it works just fine. I reduced the test down a bit to remove the ma_decoder dependency. This is what I'm running:

void crash_test_instance_gh466()
{
    ma_device_config deviceConfig;
    ma_device device;

    deviceConfig = ma_device_config_init(ma_device_type_playback);
    deviceConfig.playback.format   = ma_format_f32;
    deviceConfig.playback.channels = 2;
    deviceConfig.sampleRate        = 44100;
    deviceConfig.dataCallback      = data_callback;
    deviceConfig.pUserData         = NULL;

    if (ma_device_init(NULL, &deviceConfig, &device) != MA_SUCCESS) {
        printf("Failed to open playback device.\n");
        return;
    }

    if (ma_device_start(&device) != MA_SUCCESS) {
        printf("Failed to start playback device.\n");
        ma_device_uninit(&device);
        return;
    }

    ma_sleep(5000);

    ma_device_uninit(&device);
}

void crash_test_gh466()
{
    crash_test_instance_gh466();
    crash_test_instance_gh466();
}

I just call the crash_test_gh466() function from the entry point and it works without any crashing. Looking at the miniaudio code, everything looks fine on the surface. This might be something that the community will need to help me with because I don't have a practical way of addressing it. What emulator are you using? My instinct is that an edge case is getting hit which Oboe is aware of and is working around. I don't know what it'd be, however.

I've added the "help wanted" tag to this ticket. If the community doesn't respond after a period of time I'll close this one.

@znakeeye
Copy link

I'm wondering if issue #590 could be related. Oboe is aware of that edge case.

Are you able to replicate this bug with dev branch?

@mackron
Copy link
Owner

mackron commented Mar 17, 2023

This has been open for close to a year now and considering I haven't been able to replicate it and the community hasn't presented a concrete solution I'm going to go ahead and close this one. Happy to reopen this if someone else reports the same issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants