AudioTrack init failed when Bluetooth is connected

[gemiren]

This bug was first observed after updating from ExoPlayer 2.11.8 to 2.12.0 and still happens with latest ExoPlayer 2.16.0.

I haven't been able to reproduce the bug myself yet but I've received many bug reports from my users. The bug happens when Bluetooth headset is connected, start playing will fail with AudioTrack init failed. Disconnecting the Bluetooth headset, then it will start play without any issue.

com.google.android.exoplayer2.ExoPlaybackException: MediaCodecAudioRenderer error, index=1, format=Format(null, null, null, audio/raw, null, -1, null, [-1, -1, -1.0], [2, 44100]), format_supported=YES
	at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(SourceFile:43)
	at android.os.Handler.dispatchMessage(Handler.java:102)
	at android.os.Looper.loop(Looper.java:164)
	at android.os.HandlerThread.run(HandlerThread.java:65)
Caused by: e.b.b.b.o3.u$b: AudioTrack init failed 0 Config(44100, 12, 1058400)
	at com.google.android.exoplayer2.audio.DefaultAudioSink$Configuration.buildAudioTrack(SourceFile:5)
	at com.google.android.exoplayer2.audio.DefaultAudioSink.buildAudioTrack(SourceFile:2)
	at com.google.android.exoplayer2.audio.DefaultAudioSink.initializeAudioTrack(SourceFile:2)
	at com.google.android.exoplayer2.audio.DefaultAudioSink.handleBuffer(SourceFile:16)
	at com.google.android.exoplayer2.audio.MediaCodecAudioRenderer.processOutputBuffer(SourceFile:7)
	at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.drainOutputBuffer(SourceFile:32)
	at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.render(SourceFile:16)
	at com.google.android.exoplayer2.ExoPlayerImplInternal.doSomeWork(SourceFile:14)
	at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(SourceFile:25)

My player code is:

        val renderersFactory = DefaultRenderersFactory(context)
        renderersFactory.setEnableAudioTrackPlaybackParams(true)

        val adaptiveTrackSelectionFactory = AdaptiveTrackSelection.Factory()
        val trackSelector = DefaultTrackSelector(DefaultTrackSelector.Parameters.DEFAULT_WITHOUT_CONTEXT, adaptiveTrackSelectionFactory)

        player = ExoPlayer.Builder(context, renderersFactory)
                .setTrackSelector(trackSelector)
                .build()

This bug mostly happens on low end devices but it can also happen on high end devices such as Pixel 3.

Any help is appreciated.

[tonihei]

This bug was first observed after updating from ExoPlayer 2.11.8 to 2.12.0 and still happens with latest ExoPlayer 2.16.0.

How confident are you that this problem didn't occur with 2.11.8? If this is indeed the case then something in the DefaultAudioSink setup or how the class is being used must have changed in 2.12.0 that broke this use case. One setting that was new in 2.12.0 and you seem to be using is setEnableAudioTrackPlaybackParams. Have you ever tried disabling this feature (or haven't used it while these errors already occurred)?

The bug happens when Bluetooth headset is connected

Just to clarify: This bug happens when the headset is already connected when the playback starts. So it's not related to plugging in the headset during playback?

Also, did your error reports contain anything special about the type or capabilities of the headsets involved?

This bug mostly happens on low end devices

Generally, the initialization of an AudioTrack may fail if the device runs out of resources to create this audio track. This doesn't explain why this should be related to the Bluetooth headsets, but it could be an explanation for this type of error in general. If you happen to have a device where this issue occurred, you could run adb shell dumpsys media.audio_flinger to get a list of AudioTracks with associated metadata. This would tell you if there is a leak of unreleased AudioTracks somewhere that causes this issue.

[gemiren]

How confident are you that this problem didn't occur with 2.11.8?

I can't say this problem never occurred with 2.11.8. I may receive one similar bug report in a week with 2.11.8. With 2.12.0, I receive around 10 related bug reports every day. I tried reverting to 2.11.8 and those affected users told me this problem went away. Obviously this bug happens a lot more frequently since 2.12.0.

I've tried disabling setEnableAudioTrackPlaybackParams, this error still occurred.

This bug happens when the headset is already connected when the playback starts. So it's not related to plugging in the headset during playback?

Based on the information I gathered this bug happens when the headset is already connected before the playback starts. I haven't asked my users to test whether this bug still happens when plugging in the headset during playback.

did your error reports contain anything special about the type or capabilities of the headsets involved?

I saw different headsets were used. I don't think it's related to a specific headset model.

This doesn't explain why this should be related to the Bluetooth headsets

Yes, this is what puzzles me most. One user even sent me a video showed he couldn't start playing with headset connected. He disconnected the headset, then it played just fine.

Below is one dumpsys media.audio_flinger I received from my user. The device used is ZTE Z855 which only has 2G memory. pid: 4444 is my app.

DUMP OF SERVICE media.audio_flinger:
Library audio_pre_processing
  Noise Suppression / Qualcomm Fluence
    UUID: 1d97bb0b-9e2f-4403-9ae3-58c2554306f8
    TYPE: 58b4b260-8e06-11e0-aa8e-0002a5d5c51b
    apiVersion: 00020000
    flags: 00000203
  Acoustic Echo Canceler / Qualcomm Fluence
    UUID: 0f8d0d2a-59e5-45fe-b6e4-248c8a799109
    TYPE: 7b491460-8d4d-11e0-bd61-0002a5d5c51b
    apiVersion: 00020000
    flags: 00000203
Library offload_bundle
  (no effects)
Library proxy
  Proxy / AOSP
    UUID: af8da7e0-2ca1-11e3-b71d-0002a5d5c51b
    TYPE: ec7178ec-e5e1-4432-a3f4-4657e6795210
    apiVersion: 00020000
    flags: 00000050
  Visualizer / The Android Open Source Project
    UUID: 1d0a1a53-7d5d-48f2-8e71-27fbd10d842c
    TYPE: e46b26a0-dddd-11db-8afd-0002a5d5c51b
    apiVersion: 00020000
    flags: 00400008
  Qualcomm Technologies Insert Preset Reverb / Qualcomm Technologies, Inc.
    UUID: f3e178d2-ebcb-408e-8357-0002a5d5c51b
    TYPE: 47382d60-ddd8-11db-bf3a-0002a5d5c51b
    apiVersion: 00020000
    flags: 00400088
  Qualcomm Technologies Auxiliary Preset Reverb / Qualcomm Technologies, Inc.
    UUID: 1b78f587-6d1c-422e-8b84-0002a5d5c51b
    TYPE: 47382d60-ddd8-11db-bf3a-0002a5d5c51b
    apiVersion: 00020000
    flags: 00400001
  Qualcomm Technologies Insert Environmental Reverb / Qualcomm Technologies, Inc.
    UUID: b707403a-a1c1-4291-9573-0002a5d5c51b
    TYPE: c2e5d5f0-94bd-4763-9cac-4e234d06839e
    apiVersion: 00020000
    flags: 00400088
  Qualcomm Technologies Auxiliary Environmental Reverb / Qualcomm Technologies, Inc.
    UUID: 48404ac9-d202-4ccc-bf84-0002a5d5c51b
    TYPE: c2e5d5f0-94bd-4763-9cac-4e234d06839e
    apiVersion: 00020000
    flags: 00400001
  Equalizer / NXP Software Ltd.
    UUID: c8e70ecd-48ca-456e-8a4f-0002a5d5c51b
    TYPE: 0bed4300-ddd6-11db-8f34-0002a5d5c51b
    apiVersion: 00020000
    flags: 00400048
  Qualcomm Technologies Virtualizer / Qualcomm Technologies, Inc.
    UUID: d3467faa-acc7-4d34-acaf-0002a5d5c51b
    TYPE: 37cc2c00-dddd-11db-8577-0002a5d5c51b
    apiVersion: 00020000
    flags: 00400290
  Qualcomm Technologies Bass Boost / Qualcomm Technologies, Inc.
    UUID: 14804144-a5ee-4d24-aa88-0002a5d5c51b
    TYPE: 0634f220-ddd4-11db-a0fc-0002a5d5c51b
    apiVersion: 00020000
    flags: 00400290
Library loudness_enhancer
  Loudness Enhancer / The Android Open Source Project
    UUID: fa415329-2034-4bea-b5dc-5b381c8d1e2c
    TYPE: fe3199be-aed0-413f-87bb-11260eb63cf1
    apiVersion: 00020000
    flags: 00000008
Library downmix
  Multichannel Downmix To Stereo / The Android Open Source Project
    UUID: 93f04452-e4fe-41cc-91f9-e475b6d1d69f
    TYPE: 381e49cc-a858-4aa2-87f6-e8388e7601b2
    apiVersion: 00020000
    flags: 00000008
Library visualizer_hw
  (no effects)
Library visualizer_sw
  (no effects)
Library qcreverb
  (no effects)
Library qcvirt
  (no effects)
Library qcbassboost
  (no effects)
Library reverb
  (no effects)
Library bundle
  Volume / NXP Software Ltd.
    UUID: 119341a0-8469-11df-81f9-0002a5d5c51b
    TYPE: 09e8ede0-ddde-11db-b4f6-0002a5d5c51b
    apiVersion: 00020000
    flags: 00000050
Clients:
  pid: 3405
  pid: 4444
Notification Clients:
  pid: 342
  pid: 353
  pid: 2211
  pid: 3405
  pid: 3903
  pid: 4444
  pid: 10759
  pid: 13644
Global session refs:
  session   pid count
        9  3405     1
       89  4444     4
       97 13644     1
Hardware status: 0
Standby Time mSec: 3000

Output thread 0xadd839c0 type 0 (MIXER):
  Thread name: AudioOut_D
  I/O handle: 13
  TID: 612
  Standby: no
  Sample rate: 48000 Hz
  HAL frame count: 960
  HAL format: 0x1 (pcm16)
  HAL buffer size: 3840 bytes
  Channel count: 2
  Channel mask: 0x00000003 (front-left, front-right)
  Processing format: 0x1 (pcm16)
  Processing frame size: 4 bytes
  Pending config events: none
  Output device: 0x2 (SPEAKER)
  Input device: 0 (NONE)
  Audio source: 0 (default)
  Normal frame count: 960
  Last write occurred (msecs): 15
  Total writes: 26973
  Delayed writes: 0
  Blocked in write: yes
  Suspend count: 0
  Sink buffer : 0xae57e000
  Mixer buffer: 0xae564000
  Effect buffer: 0xae57f000
  Fast track availMask=0xfe
  Standby delay ns=3000000000
  AudioStreamOut: 0xaee2d0e0 flags 0x2 (PRIMARY)
  Frames written: 25894080
  Suspended frames: 0
  Hal stream dump:
  Thread throttle time (msecs): 114
  AudioMixer tracks: 0x00000001
  Master mono: off
  FastMixer not initialized
  Stream volumes in dB: 0:0, 1:-16, 2:-17, 3:-33, 4:-17, 5:-13, 6:0, 7:-6, 8:-17, 9:0, 10:-40, 11:0, 12:0
  Normal mixer raw underrun counters: partial=0 empty=0
  1 Tracks of which 1 are active
    Name Active Client Type      Fmt Chn mask Session fCount S F SRate  L dB  R dB    Server Main buf  Aux Buf Flags UndFrmCnt
       0    yes   4444    3 00000001 00000003      89 113408 A 3 44100     0     0  01235B92 0xaccff000 0x0 0x000         0 
  1 Effect Chains
    3 effects for session 89
	In buffer   Out buffer   Active tracks:
	0xaccff000  0xae57f000   1
	Effect ID 11:
		Session Status State Engine:
		00089   000    000   0xad84a6d0
		Descriptor:
		- UUID: C8E70ECD-48CA-456E-8A4F-0002A5D5C51B
		- TYPE: 0BED4300-DDD6-11DB-8F34-0002A5D5C51B
		- apiVersion: 00020000
		- flags: 00400048 (conn. mode: insert, insert pref: first, volume mgmt: implements control, input mode: not set, output mode: not set, offloadable)
		- name: Equalizer
		- implementor: NXP Software Ltd.
		- Input configuration:
			Frames  Smp rate Channels Format Buffer
			00960   48000    00000003      1 (pcm16) 0xaccff000
		- Output configuration:
			Buffer     Frames  Smp rate Channels Format
			0xaccff000 00960   48000    00000003 1 (pcm16)
		1 Clients:
			  Pid Priority Ctrl Locked client server
			 4444        0  yes    yes      0      0
	Effect ID 27:
		Session Status State Engine:
		00089   000    003   0xad84a8e0
		Descriptor:
		- UUID: FA415329-2034-4BEA-B5DC-5B381C8D1E2C
		- TYPE: FE3199BE-AED0-413F-87BB-11260EB63CF1
		- apiVersion: 00020000
		- flags: 00000008 (conn. mode: insert, insert pref: first, volume mgmt: none, input mode: not set, output mode: not set)
		- name: Loudness Enhancer
		- implementor: The Android Open Source Project
		- Input configuration:
			Frames  Smp rate Channels Format Buffer
			00960   48000    00000003      1 (pcm16) 0xaccff000
		- Output configuration:
			Buffer     Frames  Smp rate Channels Format
			0xaccff000 00960   48000    00000003 1 (pcm16)
		1 Clients:
			  Pid Priority Ctrl Locked client server
			 4444        0  yes    yes      0      0
	Effect ID 19:
		Session Status State Engine:
		00089   000    003   0xad84a7c0
		Descriptor:
		- UUID: 14804144-A5EE-4D24-AA88-0002A5D5C51B
		- TYPE: 0634F220-DDD4-11DB-A0FC-0002A5D5C51B
		- apiVersion: 00020000
		- flags: 00400290 (conn. mode: insert, insert pref: last, volume mgmt: requires indication, device indication: requires updates, input mode: not set, output mode: not set, offloadable)
		- name: Qualcomm Technologies Bass Boost
		- implementor: Qualcomm Technologies, Inc.
		- Input configuration:
			Frames  Smp rate Channels Format Buffer
			00960   48000    00000003      1 (pcm16) 0xaccff000
		- Output configuration:
			Buffer     Frames  Smp rate Channels Format
			0xae57f000 00960   48000    00000003 1 (pcm16)
		1 Clients:
			  Pid Priority Ctrl Locked client server
			 4444        0  yes    yes      0      0

Output thread 0xadb83600 type 0 (MIXER):
  Thread name: AudioOut_15
  I/O handle: 21
  TID: 618
  Standby: yes
  Sample rate: 48000 Hz
  HAL frame count: 240
  HAL format: 0x1 (pcm16)
  HAL buffer size: 960 bytes
  Channel count: 2
  Channel mask: 0x00000003 (front-left, front-right)
  Processing format: 0x5 (pcmfloat)
  Processing frame size: 8 bytes
  Pending config events: none
  Output device: 0 (NONE)
  Input device: 0 (NONE)
  Audio source: 0 (default)
  Normal frame count: 960
  Last write occurred (msecs): 875518
  Total writes: 0
  Delayed writes: 0
  Blocked in write: no
  Suspend count: 0
  Sink buffer : 0xaee62000
  Mixer buffer: 0xaee5f000
  Effect buffer: 0xaee61000
  Fast track availMask=0xfc
  Standby delay ns=3000000000
  AudioStreamOut: 0xaee2d150 flags 0x4 (FAST)
  Frames written: 0
  Suspended frames: 0
  PipeSink frames written: 0
  Hal stream dump:
  Thread throttle time (msecs): 0
  AudioMixer tracks: 0x00000001
  Master mono: off
  FastMixer command=COLD_IDLE writeSequence=0 framesWritten=0
            numTracks=0 writeErrors=0 underruns=0 overruns=0
            sampleRate=0 frameCount=0 measuredWarmup=0 ms, warmupCycles=0
            mixPeriod=nan ms
  No FastMixer statistics available currently
  Fast tracks: sMaxFastTracks=8 activeMask=0
  Index Active Full Partial Empty  Recent Ready    Written
      0     no    0       0     0    full     0          0
      1     no    0       0     0    full     0          0
      2     no    0       0     0    full     0          0
      3     no    0       0     0    full     0          0
      4     no    0       0     0    full     0          0
      5     no    0       0     0    full     0          0
      6     no    0       0     0    full     0          0
      7     no    0       0     0    full     0          0
  Stream volumes in dB: 0:0, 1:-16, 2:-17, 3:-40, 4:-17, 5:-13, 6:0, 7:-6, 8:-17, 9:0, 10:-40, 11:0, 12:0
  Normal mixer raw underrun counters: partial=0 empty=0
  1 Tracks of which 0 are active
    Name Active Client Type      Fmt Chn mask Session fCount S F SRate  L dB  R dB    Server Main buf  Aux Buf Flags UndFrmCnt
    F  1     no   3405    1 00000001 00000001       9    960 I 0 48000     0     0  00000000 0xaee62000 0x0 0x004         0 
  0 Effect Chains

USB audio module:
  No output streams.

  No input streams.

Reroute submix audio module:
 route[0] rate in=0 out=0, addr=[]
 route[1] rate in=0 out=0, addr=[]
 route[2] rate in=0 out=0, addr=[]
 route[3] rate in=0 out=0, addr=[]
 route[4] rate in=0 out=0, addr=[]
 route[5] rate in=0 out=0, addr=[]
 route[6] rate in=0 out=0, addr=[]
 route[7] rate in=0 out=0, addr=[]
 route[8] rate in=0 out=0, addr=[]
 route[9] rate in=48000 out=48000, addr=[]
--------- 0.017s was the duration of dumpsys media.audio_flinger

[krocard]

The audio format is stereo pcm, its suprizing it would fail.

Has any of your user shared a bug report with you? It contains the system logcat at the time of the error would gave us much more information about the issue as well as the dumpsys of media.audio_policy would give us the BT capabilities.
It would be best if the bug report was taken just after the playback failed to start and the device untouched (eg do not disconnect the bluetooth) until the bug report is full generated.
If you're unable to share bug reports or test content publicly, please send them to dev.exoplayer@gmail.com using a subject in the format "Issue #1234" ("#1234" is replaced with your issue number). Please also update this issue to indicate you've done this.

If no bug report is available, the logcat around the time of the playback failure would be helpfull.

[krocard]

The fact that it is related to Bluetooth is not overly suprizing. Bluetooth has a very complex state where a lot can go wrong. It could be for example that the Bluetooth stack errors attempting to start start playback in a particular state. We will know more when we can have the framework error logs when init fails.
What is more suprizing is that this low level error happens more or less frequently on different ExoPlayer version.

[gemiren]

Sent the bug report to dev.exoplayer@gmail.com. Thanks.