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

Error "AUDIO_OUTPUT_FLAG_FAST denied" raised on certain devices #1073

Closed Xavier-gl closed 3 years ago

Xavier-gl commented 3 years ago

Hello !! First of all, big thanks for this lib which is awesome 👍 The problem I encounter using Oboe (v1.4.3) is related to "AUDIO_OUTPUT_FLAG_FAST denied" which seems to be similar to this one: https://github.com/google/oboe/issues/1048

I'm using this code to setup my stream:

oboe::AudioStreamBuilder builder;
builder.setFormat(oboe::AudioFormat::Float)
    ->setChannelConversionAllowed(true)
    ->setChannelCount(2)
    ->setFormatConversionAllowed(true)
    ->setSampleRate(44100)
    ->setSampleRateConversionQuality(oboe::SampleRateConversionQuality::High)
    ->setPerformanceMode(oboe::PerformanceMode::LowLatency)
    ->setSharingMode(oboe::SharingMode::Exclusive)
    ->setUsage(oboe::Usage::Game)
    ->setCallback(this);

auto result = builder.openStream(&stream);

On my OnePlus 7T (android 10) using Oboe this code fails (the sound saturates badly on the first rendering) whereas the same code runs like a charm on Huawei P30 Lite (android 9).

As it reads in the logs below, I get in the Logcat "AAudioService: openStream(), could not open in EXCLUSIVE mode" and then "AUDIO_OUTPUT_FLAG_FAST denied by server" causing the current buffer to be way too large. The numFrames is 960 according to the spy put in the onAudioReady callback... vs 240 in the case of the Huawei which works fine.

============= On the ONEPLUS device (works bad)

I/OboeAudio: openStream() OUTPUT -------- OboeVersion1.4.3 -------- D/OboeAudio: AAudioLoader(): dlopen(libaaudio.so) returned 0xde3be43c3beebfe1 I/AAudio: AAudioStreamBuilder_openStream() called ---------------------------------------- I/AudioStreamBuilder: rate = 0, channels = 2, format = 5, sharing = EX, dir = OUTPUT I/AudioStreamBuilder: device = 0, sessionId = -1, perfMode = 12, callback: ON with frames = 0 I/AudioStreamBuilder: usage = 14, contentType = 2, inputPreset = 6, allowedCapturePolicy = 0 I/AudioPolicyManagerCustom: VR mode is 0, switch to primary output if request is for fast|raw D/AudioPolicyManagerCustom: non offloadable effect is enabled, try with non direct output D/AAudioServiceEndpointMMAP: open() mMapClient.uid = 10348, pid = 14870 => portHandle = 0 D/AAudioServiceEndpointMMAP: open() - openMmapStream() returned status -38 W/AAudioService: openStream(), could not open in EXCLUSIVE mode I/AudioPolicyManagerCustom: VR mode is 0, switch to primary output if request is for fast|raw D/AudioPolicyManagerCustom: non offloadable effect is enabled, try with non direct output D/AAudioServiceEndpointMMAP: open() mMapClient.uid = 1041, pid = 1007 => portHandle = 0 D/AAudioServiceEndpointMMAP: open() - openMmapStream() returned status -38 W/AAudioService: openStream(), could not open in EXCLUSIVE mode D/AudioStreamTrack: open(), request notificationFrames = -8, frameCount = 0 D/AudioTrack: set(): streamType -1, sampleRate 0, format 0x5, channelMask 0x3, frameCount 0, flags #104, notificationFrames -8, sessionId 0,transferType 1, uid -1, pid -1 I/AudioTrack: ull 2 ll! D/AudioFlinger: setParameters(): io 0, keyvalue Use_Game_Ecns=off, calling pid 14870 calling uid 10348 I/AudioPolicyManagerCustom: VR mode is 0, switch to primary output if request is for fast|raw I/AudioFlinger: AUDIO_OUTPUT_FLAGS denied by effect, session=0 old=0x4 new=0 D/AudioFlinger: Client defaulted notificationFrames to 960 for frameCount 1924 I/AudioFlinger: latencyMs:48, frameCount:1924. D/AudioFlinger: the framecount(1920) should be the tims of 960 D/AudioFlinger: AudioOut_D createTrack_l() stmType 3,typeVolume 0.016687,mute 0,fc 1920,sId 217, flags 0 D/AF::TrackHandle: OpPlayAudio: track:67 usage:14 not muted W/AudioTrack: createTrack_l(-1): AUDIO_OUTPUT_FLAG_FAST denied by server; frameCount 0 -> 1920 D/AudioTrack: Uid 10348 AudioTrack::setVolume left 1.000000 right 1.000000 W/AudioStreamTrack: open() sampleRate changed from 0 to 48000 W/AudioStreamTrack: open() flags changed from 0x00000104 to 0x00000000 W/AudioStreamTrack: open() perfMode changed from 12 to 10 I/AAudio: AAudioStreamBuilder_openStream() returns 0 = AAUDIO_OK for s#2 ---------------- D/OboeAudio: AudioStreamAAudio.open() format=2, sampleRate=48000, capacity = 1920 D/OboeAudio: AudioStreamAAudio.open: AAudioStream_Open() returned AAUDIO_OK I/OboeAudio: openStream() create a FilterAudioStream for data conversion. I/OboeAudio: configure() flowgraph converts channels: 2 to 2, format: 2 to 2, rate: 44100 to 48000, qual = 4 D/AAudio: AAudioStream_requestStart(s#2) called -------------- D/AudioTrack: ClientUid 10348 AudioTrack::start I/APM_AudioPolicyManager: startOutput() output 13, stream 3, session 217, portId 35 E/SPY: onAudioReady... D/AudioStreamLegacy: onAudioDeviceUpdate() devId 3 => 3 E/SPY: Audio: numFrames: 960 D/AAudio: AAudioStream_requestStart(s#2) returned 0 --------- E/SPY: onAudioReady... E/SPY: Audio: numFrames: 960

============= On the HUAWEI device (works fine)

I/OboeAudio: openStream() OUTPUT -------- OboeVersion1.4.3 -------- D/OboeAudio: AAudioLoader(): dlopen(libaaudio.so) returned 0x3694b6fb3f335431 D/AAudio: AAudioStreamBuilder_openStream() called ---------------------------------------- I/AudioStreamBuilder: builder_createStream tryMMap = true for output I/AAudioStream: open() rate = 0, channels = 2, format = 2, sharing = EX, dir = OUTPUT I/AAudioStream: open() device = 0, sessionId = 0, perfMode = 12, callback: ON with frames = 0 I/AAudioStream: open() usage = 14, contentType = 2, inputPreset = 6 D/AAudio: AAudioStreamBuilder_openStream() returns 0 = AAUDIO_OK for (0x767ae51100) ---------------- D/OboeAudio: AudioStreamAAudio.open() format=2, sampleRate=48000, capacity = 2400 D/OboeAudio: AudioStreamAAudio.open: AAudioStream_Open() returned AAUDIO_OK D/AudioStreamInternal_Client: setBufferSize() req = 480 => 480 I/OboeAudio: openStream() create a FilterAudioStream for data conversion. I/OboeAudio: configure() flowgraph converts channels: 2 to 2, format: 2 to 2, rate: 44100 to 48000, qual = 4 D/AudioStreamInternal_Client: setBufferSize() req = 480 => 480 D/AudioStreamInternal_Client: setBufferSize() req = 480 => 480 D/AAudio: AAudioStream_requestStart(0x767ae51100) called -------------- D/AAudio: AAudioStream_requestStart(0x767ae51100) returned 0 --------- D/AudioStreamInternalPlay_Client: callbackLoop() entering >>>>>>>>>>>>>>> E/SPY: onAudioReady... E/SPY: Audio: numFrames: 240 D/AudioStreamInternal_Client: onEventFromServer - got AAUDIO_SERVICE_EVENT_STARTED

What can I do to fix the problem ? Is it hardware related ? Thank you very much in advance for your support :)

philburk commented 3 years ago

Thanks for including the code AND the logs. That's very helpful.

Your code looks fine and should result in low latency. But I am seeing a couple odd things in the log.

D/AudioFlinger: setParameters(): io 0, keyvalue Use_Game_Ecns=off, calling pid 14870 calling uid 10348
I/AudioPolicyManagerCustom: VR mode is 0, switch to primary output if request is for fast|raw
I/AudioFlinger: AUDIO_OUTPUT_FLAGS denied by effect, session=0 old=0x4 new=0

The OnePlus has implemented a custom AudioPolicyManager. They seem to be applying a Virtual Reality effect that prevents the use of a FAST track. I will communicate with OnePlus about this.

The VR effect may be related to the "Game" usage. Try removing this line:

->setUsage(oboe::Usage::Game)

Do you now get a FAST track?

You might be able to do some experiments quickly by using OboeTester.

(the sound saturates badly on the first rendering)

Does it sound like it is clipping from being too loud? Does the sound get cleaner if you lower the volume? Or is it just quieter but still distorted? What does "first rendering" mean?

philburk commented 3 years ago

@Xavier-gl - are you enabling VR (Virtual Reality) in your app?

philburk commented 3 years ago

For reference, the internal bug number is:

b/173030073 | OnePlus T7 not getting an audio FAST track with Usage=GAME
Xavier-gl commented 3 years ago

Hello Phil and thanks for your feedback !

Do you now get a FAST track?

I have tried to remove this Usage::Game line from the stream settings. The VR log is gone but still no audio FAST track. Here are the logs I get on the OnePlus 7T device:

I/OboeAudio: openStream() OUTPUT -------- OboeVersion1.4.3 -------- I/AAudio: AAudioStreamBuilder_openStream() called ---------------------------------------- I/AudioStreamBuilder: rate = 0, channels = 2, format = 5, sharing = EX, dir = OUTPUT I/AudioStreamBuilder: device = 0, sessionId = -1, perfMode = 12, callback: ON with frames = 0 I/AudioStreamBuilder: usage = 1, contentType = 2, inputPreset = 6, allowedCapturePolicy = 0 D/AudioStreamTrack: open(), request notificationFrames = -8, frameCount = 0 D/AudioTrack: set(): streamType -1, sampleRate 0, format 0x5, channelMask 0x3, frameCount 0, flags #104, notificationFrames -8, sessionId 0, transferType 1, uid -1, pid -1 I/AudioTrack: ull 2 ll! W/AudioTrack: createTrack_l(-1): AUDIO_OUTPUT_FLAG_FAST denied by server; frameCount 0 -> 1920 D/AudioTrack: Uid 10348 AudioTrack::setVolume left 1.000000 right 1.000000 W/AudioStreamTrack: open() sampleRate changed from 0 to 48000 W/AudioStreamTrack: open() flags changed from 0x00000104 to 0x00000000 W/AudioStreamTrack: open() perfMode changed from 12 to 10 I/AAudio: AAudioStreamBuilder_openStream() returns 0 = AAUDIO_OK for s#2 ---------------- I/OboeAudio: openStream() create a FilterAudioStream for data conversion. I/OboeAudio: configure() flowgraph converts channels: 2 to 2, format: 2 to 2, rate: 44100 to 48000, cbsize: 0 to 0, qual = 4 D/AAudio: AAudioStream_requestStart(s#2) called -------------- D/AudioTrack: ClientUid 10348 AudioTrack::start D/SPY: onAudioReady... D/AAudio: AAudioStream_requestStart(s#2) returned 0 --------- D/SPY: Audio: numFrames: 960 D/AudioStreamLegacy: onAudioDeviceUpdate() devId 3 => 3 D/SPY: onAudioReady... D/SPY: Audio: numFrames: 960 D/SPY: onAudioReady... D/SPY: Audio: numFrames: 960

You might be able to do some experiments quickly by using OboeTester.

Thanks for the advice, I will give it a try !

(the sound saturates badly on the first rendering) Does it sound like it is clipping from being too loud?

Not really. The first two sounds are rendered (played) properly. Then I have observed two different behaviours. Either the audio is completely shut down (the app remains totally silent) or on the third sound play, the audio is stuck on a single note (it buzzes like mad) hence saturation.

Does the sound get cleaner if you lower the volume? Or is it just quieter but still distorted?

Volume level seems to have no effect.

What does "first rendering" mean?

Just first sound played :)

I hope those logs can help. Have a nice day !

philburk commented 3 years ago

OnePlus reports that this has been fixed. The fix will be in a future release.

@Xavier-gl - Thanks for reporting this.