942988 - a/v sync does not care about latency after mixing in AudioFlinger

Status: RESOLVED FIXED

(Core :: Audio/Video, defect)

Description

[Sotaro Ikeda [:sotaro]]

+++ This bug was initially created as a clone of Bug #940707 +++

MediaDecoderStateMachine controls a/v sync by using BufferedAudioStream. BufferedAudioStream got audio time by using cubeb_stream_get_position(). cubeb_stream_get_position() seems to care about latency until audio track mixed by AudioFlinger, but not care about the latency after mixed until output to audio hw. And BufferedAudioStream control a/v sync. Therefore, MediaDecoderStateMachine control a/v sync without caring about the latency from mixing in AudioFlinger until audio out.

Comment 1

[Sotaro Ikeda [:sotaro]]

Android stagefright handles it in AudioPlayer::getRealTimeUsLocked().
http://androidxref.com/4.4_r1/xref/frameworks/av/media/libstagefright/AudioPlayer.cpp#704

Comment 2

[Jason Smith [:jsmith]]

What's the user impact of this bug? Is it a regression? Could this happen on all production devices?

Comment 3

[Paul Adenot (:padenot)]

- Potential bad Audio/Video synchronization, although I don't recall anybody has ever complained.
- No, it has always been like this
- Yes

Comment 4

[Sotaro Ikeda [:sotaro]]

Changed to manai?(1.4), From my experience in japanese android phone development, some people care about it in bluetooth use cases.

Comment 5

[Marco Chen [:mchen]]

(In reply to Sotaro Ikeda [:sotaro] (PTO Dec. 21 ~ Jan. 5) from comment #4)
> Changed to manai?(1.4), From my experience in japanese android phone
> development, some people care about it in bluetooth use cases

The HW latency from BT path is significant then others. I remember it is about 500~600ms on Nexus 4.

Hi Star,

Could you test it on Nexus 4 with BT AVRCP profile enabled? Thanks.

Comment 6

[Star Cheng [:scheng]]

I have tested 2 cases. 
The case1 which Nexus4 is connected with BT device supporting A2DP, the AVsync is not mapping. The other case without connection of BT A2DP device, the AVsync is mapping.

Comment 7

[Star Cheng [:scheng]]

(1)Try to get the mixer_latnecy from audioflinger. And translate mixer_latency to latency for libcube.

-------------
libmedia = dlopen("libmedia.so", RTLD_LAZY);
get_output_latency = dlsym(libmedia, "_ZN7android11AudioSystem16getOutputLatencyEPj19audio_stream_type_t");
get_output_latency(&mixer_latency, stm->stream_type);

latency = mixer_latency * samplerate / 1000; // AudioFlinger latency
-------------

(2)And then considering the latency in get_position() function. 

-------------
if (*position > latency) {
  	*position = (samplerate * msec / 1000) - latency;
}
-------------

Comment 8

[Star Cheng [:scheng]]

Attachment: Bug-942988-fix.patch

decrease audio latency in the opensl_stream_get_position() function.

Comment 9

[Paul Adenot (:padenot)]

Comment on attachment 8373202 [details] [diff] [review]
Bug-942988-fix.patch

Review of attachment 8373202 [details] [diff] [review]:
-----------------------------------------------------------------

::: media/libcubeb/src/cubeb_opensl.c
@@ +545,5 @@
> +  int rv;
> +  int32_t (*get_output_latency)(uint32_t * latency, int stream_type);
> +  int32_t mixer_latency;
> +
> +  libmedia = dlopen("libmedia.so", RTLD_LAZY);

We _really_ don't want to do complicated like dlopening stuff here, this function is hot.

Also, I feel this code should not be platform specific.

Comment 10

[Star Cheng [:scheng]]

I reference opensl_stream_get_latency() in cubeb_opensl.c file. And "libmedia = dlopen("libmedia.so", RTLD_LAZY); " is used in this function. If it need to be modified, could you provide suggestions about that?

And the audio mixer latency is platform specific. If we want to get the mixer latency from other way, I need to investigate it.

Comment 11

[Paul Adenot (:padenot)]

I think we should just make sure opensl_stream_get_latency returns the right number, query it on stream init, cache it, and use the cached value in opensl_stream_get_position.

And we should determine if all the platforms return latency compensated clock or not, and latency compensate the platform that need it.

Comment 12

[Star Cheng [:scheng]]

In the below following scenario:

1.Enter music app and play mp3 file.
2.Press home key and back to home screen (music app playing in bg)
3.Enter settings app and connect BT headset.

The mixer latency is different between routing audio path to speaker or BT headset. 
(speaker : 50ms / BT headset : 258ms in Nexus4 device)

In order to avoid cache error mixer latency in above case, I want to cache "libmedia"  & get_output_latency() function pointer in opensl_stream_init(), and then use dlclose() in opensl_stream_destroy() function.

Comment 13

[Star Cheng [:scheng]]

(In reply to Star Cheng [:scheng] from comment #12)
> In the below following scenario:
> 
> 1.Enter music app and play mp3 file.
> 2.Press home key and back to home screen (music app playing in bg)
> 3.Enter settings app and connect BT headset.
> 
> The mixer latency is different between routing audio path to speaker or BT
> headset. 
> (speaker : 50ms / BT headset : 258ms in Nexus4 device)
> 
> In order to avoid cache error mixer latency in above case, I want to cache
> "libmedia"  & get_output_latency() function pointer in opensl_stream_init(),
> and then use dlclose() in opensl_stream_destroy() function.

And to use get_output_latency() in the opensl_stream_get_position() & opensl_stream_get_latency() to get mixer latency.

Comment 14

[Paul Adenot (:padenot)]

(In reply to Star Cheng [:scheng] from comment #12)
> In order to avoid cache error mixer latency in above case, I want to cache
> "libmedia"  & get_output_latency() function pointer in opensl_stream_init(),
> and then use dlclose() in opensl_stream_destroy() function.

That's fine, yes. We can certainly do a function call there.

Comment 15

[Star Cheng [:scheng]]

Attachment: Bug-942988-fix_v2.patch

use global static variable to cache libmedia object.

Comment 16

[Star Cheng [:scheng]]

Comment on attachment 8377332 [details] [diff] [review]
Bug-942988-fix_v2.patch

cache the libmedia object

Comment 17

[Paul Adenot (:padenot)]

Comment on attachment 8377332 [details] [diff] [review]
Bug-942988-fix_v2.patch

Review of attachment 8377332 [details] [diff] [review]:
-----------------------------------------------------------------

::: media/libcubeb/src/cubeb_opensl.c
@@ +493,5 @@
>    }
>  
>    *stream = stm;
>  
> +  if (!glibmedia) {

This is racy: what if we try to initialize two cubeb_stream at the same time?

Also, http://software.intel.com/en-us/blogs/2013/01/06/benign-data-races-what-could-possibly-go-wrong

Two possibilities to fix this:
- Put the library in the cubeb struct, open it in cubeb_init, close it in cubeb_destroy
- Leverage the fact that dlopens on the same library are refcounted: if you call dlopen twice, you will have to call dlclose twice, and then it will be freed.

The first solution is better, imo.

@@ +537,5 @@
> +    dlclose(glibmedia);
> +    glibmedia = NULL;
> +  }
> +
> +  if (get_output_latency) get_output_latency = NULL;

Always put braces on if () statements, and put the content on a new line.

@@ +583,5 @@
>  
> +  if (get_output_latency) {
> +    rv = get_output_latency(&mixer_latency, stm->stream_type);
> +	if (rv)
> +	  return CUBEB_ERROR;

Braces around if. Also, the indentation is slightly off, here.

@@ +585,5 @@
> +    rv = get_output_latency(&mixer_latency, stm->stream_type);
> +	if (rv)
> +	  return CUBEB_ERROR;
> +  } else {
> +	return CUBEB_ERROR;

Two space indents, please.

@@ +591,5 @@
> +
> +  if (msec > mixer_latency)
> +    *position = samplerate * (msec - mixer_latency) / 1000;
> +  else
> +    *position = 0;

Braces around if () statements.

@@ +614,5 @@
>    /* audio_stream_type_t is an int, so this is okay. */
> +  if (get_output_latency) {
> +    rv = get_output_latency(&mixer_latency, stm->stream_type);
> +	if (rv)
> +	  return CUBEB_ERROR;

Braces around if () statements.

@@ +616,5 @@
> +    rv = get_output_latency(&mixer_latency, stm->stream_type);
> +	if (rv)
> +	  return CUBEB_ERROR;
> +  } else {
> +	return CUBEB_ERROR;

Two space indents.

Comment 18

[Star Cheng [:scheng]]

Attachment: Bug-942988-fix_v3.patch

1. add member variable in cubeb struct and dlopen() in cubeb_init()
2. dlcolse() libmedia in cubeb_destroy()
3. remove dlopen() operation in cubeb_stream_init()
4.fix the braces & indents

Comment 19

[Paul Adenot (:padenot)]

Comment on attachment 8388442 [details] [diff] [review]
Bug-942988-fix_v3.patch

Review of attachment 8388442 [details] [diff] [review]:
-----------------------------------------------------------------

::: media/libcubeb/src/cubeb_opensl.c
@@ +509,5 @@
> +    if (!get_output_latency) {
> +      opensl_destroy(ctx);
> +      return CUBEB_ERROR;
> +    }
> +  }

I think you should put the function pointer in the cubeb struct. We have the guarantee that the cubeb instance outlives the streams. Here, you have no lock protecting get_output_latency, and it can be read and written from multiple threads at the same time, corrupting memory.

So, to summarize:
- Put the get_output_library in the cubeb struct
- dlopen, dlsym in cubeb_init
- avoid non-const globals

@@ +527,5 @@
>    }
> +
> +  if (get_output_latency) {
> +    get_output_latency = NULL;
> +  }

Same problem. But since get_output_latency will be in the cubeb struct, we won't need to do anything.

Comment 20

[Star Cheng [:scheng]]

Attachment: Bug-942988-fix_v4.patch

1.Put the get_output_library() function pointer in the cubeb struct
2.dlopen, dlsym in cubeb_init()

Comment 21

[Paul Adenot (:padenot)]

Comment on attachment 8396231 [details] [diff] [review]
Bug-942988-fix_v4.patch

Review of attachment 8396231 [details] [diff] [review]:
-----------------------------------------------------------------

r+ with comments addressed. Can you also fix the commit message before landing?

Thanks!

::: media/libcubeb/src/cubeb_opensl.c
@@ +374,5 @@
>    if (ctx->engObj)
>      (*ctx->engObj)->Destroy(ctx->engObj);
> +  if (ctx->get_output_latency) {
> +    ctx->get_output_latency = NULL;
> +  }

This is not necessary, but not harmless.

@@ +569,5 @@
>      return CUBEB_ERROR;
>  
>    samplerate = stm->bytespersec / stm->framesize;
>  
> +  if (stm->context->get_output_latency) {

Technically, this can't be null, or we would have errored out at the context creation. Can you please remove it?

@@ +601,5 @@
>      return CUBEB_ERROR;
>    }
>  
> +  /* audio_stream_type_t is an int, so this is okay. */
> +  if (stm->context->get_output_latency) {

Same remark.

Comment 22

[Star Cheng [:scheng]]

Attachment: Bug-942988-patch-reviewed

1.remove check "stm->context->get_output_latency" is null or not
2.TBPL result : https://tbpl.mozilla.org/?tree=Try&rev=cfd1d77f5e88
3.add reviewer - :padenot

Comment 23

[Paul Adenot (:padenot)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/42b7019920c2

Comment 24

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/42b7019920c2

Comment 25

[Jason Smith [:jsmith]]

Mass-modify - removal of no longer relevant blocking flags.