1151499 - [Audio Channel] The radio audio is played through the device speaker at maximum volume (unadjustable) when listening to the radio through headphones and using the dialer keypad

Status: VERIFIED FIXED

(Firefox OS Graveyard :: AudioChannel, defect)

Description

[Joshua Mitchell (Inactive)]

Attachment: logcat_20150406_0923.txt

Description:
Listening to radio over headphones and then tapping on a number in the dialer-pad will cause the radio to play through the device speaker at full-volume. You can not adjust the volume down when this happens. It is very sudden and jarring to the user.


Repro Steps:
1) Update a Flame to 20150406010204
2) Plug in headphones and launch Radio app
3) Find a radio station to play
4) Minimize the radio app, and launch the dialer\
5) Tap on a digit / button

Actual:
Radio app audio is blasted out of the device speaker


Expected:
Radio app audio will remain through the headset and will dim for key-press audio then return to normal levels

Environmental Variables:
Device: Flame 3.0
Build ID: 20150406010204
Gaia: ef61ebbe5de8c2c9fc2a8f74a12455044c3b82e9
Gecko: 4fe763cbe196
Gonk: b83fc73de7b64594cd74b33e498bf08332b5d87b
Version: 40.0a1 (3.0)
Firmware Version: v18D-1
User Agent: Mozilla/5.0 (Mobile; rv:40.0) Gecko/40.0 Firefox/40.0

Repro frequency: 7/7
See attached: logcat

Comment 1

[Joshua Mitchell (Inactive)]

This issue does not reproduce on 2.2 

Actual results: All audio continues to play through the headphones

Device: Flame 2.2 (KK - Nightly - Full Flash - 319mem)
Build ID: 20150406002503
Gaia: a6351e1197d54f8624523c2db9ba1418f2aa046f
Gecko: c3335a5d3063
Gonk: ebad7da532429a6f5efadc00bf6ad8a41288a429
Version: 37.0 (2.2)
Firmware Version: v18D-1
User Agent: Mozilla/5.0 (Mobile; rv:37.0) Gecko/37.0 Firefox/37.0

Comment 2

[Peter Bylenga [:PBylenga]]

[Blocking Requested - why for this release]:
Functional regression that has potential to break speakers and/or damage hearing.

Requesting a window.

Comment 3

[Brogan Zumwalt [Inactive]]

B2G-Inbound Regression Window:

Last working B2G-Inbound build:
Device: Flame 3.0
BuildID: 20150226045809
Gaia: c5b086914cba6eb98961724423a0563d00d1f312
Gecko: 2989a2a4b027
Version: 39.0a1
Firmware Version: v18D-1
User Agent: Mozilla/5.0 (Mobile; rv:39.0) Gecko/39.0 Firefox/39.0

First broken B2G-Inbound build:
Device: Flame 3.0
Build ID: 20150226075812
Gaia: 0f2dbade8a410101ef3c6b7ca804c4f8f2c6ad2a
Gecko: 7915d40f0723
Version: 39.0a1 (3.0)
Firmware Version: v18D-1
User Agent: Mozilla/5.0 (Mobile; rv:39.0) Gecko/39.0 Firefox/39.0


Working Gaia with Broken Gecko issue does NOT reproduce:
Gaia: c5b086914cba6eb98961724423a0563d00d1f312
Gecko: 7915d40f0723

Working Gecko with Broken Gaia issue DOES reproduce:
Gaia: 0f2dbade8a410101ef3c6b7ca804c4f8f2c6ad2a
Gecko: 2989a2a4b027


B2G-Inbound Pushlog:
https://github.com/mozilla-b2g/gaia/compare/c5b086914cba6eb98961724423a0563d00d1f312...0f2dbade8a410101ef3c6b7ca804c4f8f2c6ad2a


Issue appears to occur due to changes made in bug 1102814

Comment 4

[KTucker [:KTucker][Inactive 3/4/2016]]

Gabriele, can you take a look at this please? This looks to be caused by the landing for bug 1102814.

Comment 5

[Gabriele Svelto [:gsvelto]]

Bug 1102814 only changed which audio channel the dialer uses so should not be the direct cause of this issue. This sounds like a mixing or audio channel routing problem from within Gecko. Needinfo'ing Alastor and Andrea to see if they know what might be causing this.

Comment 6

[Alastor Wu [:alwu]]

OK, I will check it!
Keep ni for tracking.

Comment 7

[Andrea Marchesini [:baku]]

Alastor, NI me if you need help.

Comment 8

[Alastor Wu [:alwu]]

When I tap the dialer, I found that the audio streams in audio output have some strange changing, I am not sure what is the root cause. I guess that maybe the question is in the gonk or audio hardware. 

Question 1:
From the dumping status, we can see some streams be muted suddenly, why?

Question 2:
When I use the music (it also use the MUSIC stream) to test this condition, it doesn't have error.
When we play the music, the notification would come out from the headset. But when we play the FM, the notification would come from speaker. It's very strange.

I will trace it more details.
Here is the dumpsys of audio policy status.

---

# Play FM
Outputs dump:
- Output 2 dump:
 Sampling rate: 48000
 Format: 00000001
 Channels: 00000003
 Latency: 80
 Flags 00000002
 Devices 00000004
 Stream volume refCount muteCount
 00     1.000     00       00
 01     0.037     00       00
 02     0.016     00       00
 03     0.141     01       00
 04     0.033     00       00
 05     0.016     00       00
 06     -1.000    00       00
 07     0.063     00       00
 08     0.000     00       00
 09     0.000     00       00
 10     1.000     00       00

# Play FM, then tap the dialer
Outputs dump:
- Output 2 dump:
 Sampling rate: 48000
 Format: 00000001
 Channels: 00000003
 Latency: 80
 Flags 00000002
 Devices 00000006
 Stream volume refCount muteCount
 00     0.063     00       01
 01     0.000     00       01
 02     0.063     00       00
 03     0.000     01       01        <-- suddenly muted?? 
 04     0.099     00       00            but there is still sound out from speaker....
 05     0.000     01       01
 06     -1.000    00       01
 07     0.000     00       01
 08     0.000     00       01
 09     0.000     00       01
 10     1.000     00       01

---

# Play music
- Output 101 dump:
 Sampling rate: 44100
 Format: 01000000
 Channels: 00000003
 Latency: 96
 Flags 00000031
 Devices 00000004
 Stream volume refCount muteCount
 00     1.000     00       00
 01     0.037     00       00
 02     0.016     00       00
 03     0.141     01       00
 04     0.033     00       00
 05     0.016     00       00
 06     -1.000    00       00
 07     0.063     00       00
 08     0.000     00       00
 09     0.000     00       00
 10     1.000     00       00

# Play music, then tap dialer
Outputs dump:
- Output 2 dump:
 Sampling rate: 48000
 Format: 00000001
 Channels: 00000003
 Latency: 80
 Flags 00000002
 Devices 00000004
 Stream volume refCount muteCount
 00     1.000     00       00
 01     0.037     00       00
 02     0.016     00       00
 03     0.141     00       00
 04     0.033     00       00
 05     0.016     01       00
 06     -1.000    00       00
 07     0.063     00       00
 08     0.000     00       00
 09     0.000     00       00
 10     1.000     00       00
- Output 101 dump:
 Sampling rate: 44100
 Format: 01000000
 Channels: 00000003
 Latency: 96
 Flags 00000031
 Devices 00000004
 Stream volume refCount muteCount
 00     1.000     00       00
 01     0.037     00       00
 02     0.016     00       00
 03     0.141     01       00
 04     0.033     00       00
 05     0.016     00       00
 06     -1.000    00       00
 07     0.063     00       00
 08     0.000     00       00
 09     0.000     00       00
 10     1.000     00       00

Comment 10

[Alastor Wu [:alwu]]

On Android audio policy, the notification is allowed to playback from the both speaker and receiver, even when the earphone is plugged in.

It seems that we didn't stop the android audio track when we have no sound from the dialer, so that the Android thought that the notification still existed. Because of that, the FM would come out from the speaker.

Here I will describe the audio behavior when we play the notification during the FM.

[Normal situation]
1. Play notification 
   - notification refCount = 1, in the audio flinger
2. In Gecko audio channel service, fade the FM, play notification
3. In Android audio policy, muted FM, play notification 
   - change output device to both speaker and receiver
4. Stop notification 
   - notification refCount = 0, in the audio flinger
5. In Android audio policy, unmuted FM
   - change output device back to receiver
6. In Gecko audio channel service, set the FM to normal volume

[Bug situation]
In the step 4, we didn't stop the Android audio track, so that the refCount of notification is still 1. Therefore, the output device didn't be changed back to receiver. 

---

We should change the behavior of the MediaStreamGraph, stopping the Android audio track when it have no sound output.

Comment 11

[Alastor Wu [:alwu]]

[Root cause]
When there is no sound, we don't release the refCount of the notification stream in the audio finger, so that the audio policy would set the output device to both speaker and receiver. 

The refCount doesn't be released because of the cubeb stream doesn't be stopped. Whenever the MSG starts, the cubeb streams would be created to drive the MSG. Then, the audio flinger would add the refCount of the corresponding stream.

[Proposal]
Here is my rough idea to solve this issue.
Could we switch the audio driver to the system clock when there are no sound?
Like that,
(1) Press dialer, sound start       -> audio clock
(2) Sound stop, no sound be heard   -> system clock
(3) Press dialer again, sound start -> audio clock
(4) Sound stop, no sound be heard   -> system clock

---

Hi, JW,
Could you give me some suggestions?
Very appreciate :)

Comment 12

[JW Wang [:jwwang] [:jw_wang]]

I prefer to call AudioCallbackDriver::WaitForNextIteration() to enter sleeping instead of switching graph driver. However, the code of AudioCallbackDriver::WaitForNextIteration() is disabled. You can ni :padenot for more insights.

Comment 13

[Paul Adenot (:padenot)]

I'm landing bug 1094764 today, which will allow the dialer to drop the close the audio flinger stream when needed, by doing `AudioContext.suspend()`, and `AudioContext.resume()` when it's needed again.

Comment 14

[Alastor Wu [:alwu]]

Now I'm studying the patch of the bug 1094764, maybe that can help to solve this issue.

Comment 15

[Alastor Wu [:alwu]]

Attachment: [WIP] Switch driver when the stream is muted

The patch is WIP. 
Now I switch the driver when the stream is muted, that can fix this issue.
But there still has some parts need to modify.

Comment 17

[Paul Adenot (:padenot)]

Comment on attachment 8595196 [details] [diff] [review]
[WIP] Switch driver when the stream is muted

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

::: dom/media/webaudio/AudioDestinationNode.cpp
@@ +278,5 @@
> +          mStream->GraphImpl()->SetAudioMuted(mMuted);
> +        }
> +        bool mMuted;
> +      };
> +      aStream->GraphImpl()->AppendMessage(new Message(aStream, newInputMuted));

This is not right, you can have multiple AudioDestinationNode in a MediaStreamGraph.

Just call `suspend` on the AudioContext in JavaScript, it will handle all the logic for you.

Comment 18

[Alastor Wu [:alwu]]

Hi, Paul,
Do you think whether the Gecko need to handle with this issue (no sound, but the backend stream still exists) or let Gaia to handle these jobs?

What I worry about is that if the developers forgot to suspend the AudioContext, it still caused lots of audio channel problem. ex, this bug & bug1156586.
Thanks!

Comment 19

[Alastor Wu [:alwu]]

Hi, Paul,
There has other bugs is caused by the useless audio backend stream.
Ex. Bug 1156664, Bug 1115304.

That is a hack that somebody created a useless audio context in Gaia just in order to get the "moz-interrupt-begin/end".

If we can check the streams input status to decide whether need to open/close audio backend stream, I think we can reduce lots of bug. (If this proposal is not conflict with the concept of the AudioContext)

How do you think :)?

Comment 20

[Paul Adenot (:padenot)]

(In reply to Alastor Wu [:alwu] from comment #18)
> Hi, Paul,
> Do you think whether the Gecko need to handle with this issue (no sound, but
> the backend stream still exists) or let Gaia to handle these jobs?

It's not clear we can deal with this at the gecko level. There are a lot of valid reasons to have an AudioContext that is outputing silence, it may be simply waiting for something to happen, and want to have the audio stream ready to react as fast as possible (system level audio streams are very slow to create).

> What I worry about is that if the developers forgot to suspend the
> AudioContext, it still caused lots of audio channel problem. ex, this bug &
> bug1156586.

Maybe we could automatically suspend() AudioContexts for background apps, for some channels?

Comment 21

[Gabriele Svelto [:gsvelto]]

That sounds like a good idea. A music app will want to keep playing in the background but a game would not. Right now this choice is entirely up to the app, is it not?

Comment 22

[Alastor Wu [:alwu]]

(In reply to Paul Adenot (:padenot) from comment #20)
> It's not clear we can deal with this at the gecko level. There are a lot of
> valid reasons to have an AudioContext that is outputing silence, it may be
> simply waiting for something to happen, and want to have the audio stream
> ready to react as fast as possible (system level audio streams are very slow
> to create).
> 

Hi, Paul,
I think you are right, we shouldn't handle this case in Gecko level.
I can add some release logs to capture that in case the developers forget to suspend the AudioContexts.

> Maybe we could automatically suspend() AudioContexts for background apps,
> for some channels?

If the AudioContext is on the foreground, we shouldn't effect its behavior.
But, if it is on the background, we should automatically suspend() ALL types AudioContexts except the content type.

---

Last, would you have any plan to rebase your patch on to other branches? (ex. v2.1/v2.2)
If so, the gaia developers can modify their code to prevent similar issues.
If not, do you think whether I can switch the drivers to solve these issues? It's proper?

For example, Bug1156586,
In m-c, we can add the suspend() in ringtone app when it come to background to solve that issue.
In v2.1, we can only fixed that by removing the audio backend stream.

---

Very appreciate :)

Comment 23

[Alastor Wu [:alwu]]

(In reply to Gabriele Svelto [:gsvelto] from comment #21)
> That sounds like a good idea. A music app will want to keep playing in the
> background but a game would not. Right now this choice is entirely up to the
> app, is it not?

Hi, Gabriele,
What you mentioned has already been implemented by audio channel service, only the apps which use the content type audio can be playback in the background. 

Here I concerned about is that we should release the audio backend stream which is not content type, when its owner app is on the background.

Comment 24

[Alastor Wu [:alwu]]

Here I found that the real root cause, the previous analysis is not fully correct.

[Root cause]
The error playable state of FM resulted in that we stop the FM when we play the dialer sound.

[Situation]
In Flame, the FM use the Android::AudioSystem::Music to play. When we want to play the dialer sound which is the Android::AudioSystem::NOTIFICATION, the AudioPolicyManager would check the exist streams type to decide the strategy of the notification.

@ hardware/qcom/audio/policy_hal/AudioPolicyManager.cpp, 788
> } else if (isStreamActive(AudioSystem::MUSIC, SONIFICATION_RESPECTFUL_AFTER_MUSIC_DELAY)) {
>     // while media is playing (or has recently played), use the same device
>     device = getDeviceForStrategy(STRATEGY_MEDIA, false /*fromCache*/);
> } else {
>     // when media is not playing anymore, fall back on the sonification behavior
>     device = getDeviceForStrategy(STRATEGY_SONIFICATION, false /*fromCache*/);
> }

STRATEGY_MEDIA didn't change the output routing, but the STRATEGY_SONIFICATION is the same as the STRATEGY_ENFORCED_AUDIBLE. It would force the sound out from the speaker.

When the dialer sound want to start playback, we would unregister the FM's audio channel agent. 
If we stop the FM, then the refcount in the AudioFlinger of the FM became zero. This means that we don't have any Android::AudioSystem::Music at that time.

It caused that the AudioPolicyManager would use STRATEGY_SONIFICATION to playback the dialer sound.

Therefore, after the dialer sound stop, the FM would follow the previous output routing. The FM would be heared from both speaker and receiver.

Comment 25

[Alastor Wu [:alwu]]

Attachment: Correct the FM playable state

Wait for try-server result.
https://treeherder.mozilla.org/#/jobs?repo=try&revision=0bdabf94296e

Comment 26

[Alastor Wu [:alwu]]

Comment on attachment 8596538 [details] [diff] [review]
Correct the FM playable state

Hi, Baku,
Could you help me review this patch?

When we play the notification, the FM receives the FADE state. But the previous state checking condition would regard the FADE state as the MUTED. Therefore, we stop the FM, then resulted in this issue. You can see more analysis on the comment24.

Very appreciate :)

Comment 27

[Alastor Wu [:alwu]]

Try-result is on the comment25.

Comment 28

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/integration/b2g-inbound/rev/4a0d3a13905a

Comment 29

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/4a0d3a13905a

Comment 30

[Sharon]

This bug has been verified as "pass" on the latest build of Flame KK v2.5&master 512mb by the STR in comment 0.

Actual result: FM radio audio and dial tone can normally be heard from headset.
See attachment: Verified_Flame_KK_master.3gp
Reproduce rate: 0/10.

Device: Flame KK v2.5 512mb(Pass)
Build ID               20151201163815
Gaia Revision          07462becf08f0c26ebd64daf89646e7403a336c5
Gaia Date              2015-12-01 15:06:08
Gecko Revision         http://hg.mozilla.org/releases/mozilla-b2g44_v2_5/rev/33a575e711faf3344aa2e31ca2ea066b4cd8aafa
Gecko Version          44.0a2
Device Name            flame
Firmware(Release)      4.4.2
Firmware(Incremental)  eng.worker.20151201.154956
Firmware Date          Tue Dec  1 15:50:05 UTC 2015
Firmware Version       v18D v4
Bootloader             L1TC000118D0

Device: Flame KK master 512mb(Pass)
Build ID               20151201150223
Gaia Revision          59c8605876736b22acaaed25be00008e452149cb
Gaia Date              2015-12-01 02:58:37
Gecko Revision         https://hg.mozilla.org/mozilla-central/rev/1003fca97839fdfbfefb89c48c9e05a940bc9fb9
Gecko Version          45.0a1
Device Name            flame
Firmware(Release)      4.4.2
Firmware(Incremental)  eng.cltbld.20151201.183010
Firmware Date          Tue Dec  1 18:30:23 EST 2015
Firmware Version       v18D v4
Bootloader             L1TC000118D0

Comment 31

[Sharon]

Attachment: Verified_Flame_KK_master.3gp