814054 - [FMRadio] If you pull the headset after .5 seconds or so of plugging the headset in, FM Radio will play through the phone speakers.

Status: RESOLVED WONTFIX

(Firefox OS Graveyard :: General, defect, P1)

Description

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

## Environment :
Unagi phone, build 2012/11/20
  
## Repro :
1. plug headset in
2. launch FMradio
3. tune to a channel
4. unplug the headset
5. plug in the headset, after .5 seconds, plug out the headset

## Expected :
1. FM Radio does not play

## Actual :
1. FM Radio plays through the phone speakers.

## Note :
1. I don't think many people will try this, so I'm not noming.

Comment 1

[Vincent Liu[:vliu]]

When plug/unplug the headset, the event onAntennaChange was checked to do mozFMRadio.enable/mozFMRadio.disable(). After 5, this event was still checked and then mozFMRadio.disable() also be invoked. Even mozFMRadio.disable() was called, I didn't saw FMRadio::Disable() been called. It is really weird.... will check it further.

Comment 2

[Vincent Liu[:vliu]]

Otoro also have this issue. I am now working on otoro.

Comment 3

[Vincent Liu[:vliu]]

When I plugged in the headset, the behavior was expected.

1. FM_RADIO_OPERATION_ENABLE was received in FMRadio::Notify in FMRadio.cpp.
2. Received enabled event DOMFMRadioParent.
3. Sent Async message to inform power state changed.
4. Received DOMFMRadio:powerStateChange in DOMFMRadioChild.

But when I unplugged it, the behavior was weird.

1. FM_RADIO_OPERATION_DISABLE was received in FMRadio::Notify in FMRadio.cpp.
2. FM_RADIO_OPERATION_ENABLE was received in FMRadio::Notify in FMRadio.cpp.

The 2 in unplugged case shouldn't happens. I will look more detail.

Comment 4

[Vincent Liu[:vliu]]

Hi Justin,

When FM app was launched and then unplugged the headset. I could see the below behavior.

1. FM_RADIO_OPERATION_DISABLE was received in FMRadio::Notify in FMRadio.cpp.
   ==> info.status() = 0

2. FM_RADIO_OPERATION_ENABLE was received in FMRadio::Notify in FMRadio.cpp.
   ==> info.status() = 0

I think we shouldn't receive FM_RADIO_OPERATION_ENABLE in unplugging state. FM_RADIO_OPERATION_ENABLE was read from calling ioctl in GonkFMRadio.cpp. How should I do it further to know why this happens? Thanks.

Comment 6

[Marco Chen [:mchen]]

Is it possible that 
  1. When FM app is launched with headset, FM backend is starting to enable FM chip.
     (It needs more then one second to finish the enabling)
  2. During the enabling state, headset is unplugged.
  3. FM backend receives unplugged event but didn't do anything because enabling is still on progress.
  4. Then the enabling process is finished later.

The scenario above will cause FM to keep on enable state then output to speaker.

Will discuss with vliu.

Comment 7

[Justin Lebar (not reading bugmail)]

Marco's explanation sounds plausible to me; clearing the needinfo request.

Comment 8

[Vincent Liu[:vliu]]

(In reply to Marco Chen [:mchen] from comment #6)
> Is it possible that 
>   1. When FM app is launched with headset, FM backend is starting to enable
> FM chip.
>      (It needs more then one second to finish the enabling)
>   2. During the enabling state, headset is unplugged.
>   3. FM backend receives unplugged event but didn't do anything because
> enabling is still on progress.
>   4. Then the enabling process is finished later.
> 
> The scenario above will cause FM to keep on enable state then output to
> speaker.
> 
> Will discuss with vliu.

Hi Macro,
Yes, I agree with the problem flow and tried to work out a patch to solve it. Thanks

Comment 9

[Vincent Liu[:vliu]]

(In reply to Justin Lebar [:jlebar] from comment #7)
> Marco's explanation sounds plausible to me; clearing the needinfo request.

Hi Justin,

Even the headset had a long time in a inserted state, the unexpected FM_RADIO_OPERATION_ENABLE reply still happens at the time when I unplugged it. This unexpected reply is replied from kernel driver and might chaos the state. That's the reason why I need to know its root cause. Do you have any idea to check it? Thanks

Comment 10

[Vincent Liu[:vliu]]

Attachment: WIP V1. r=Justin Lebar

NOTE: If blocking-basecamp+ is set, just land it for now.
Hi Justin,

Here comes out my idea for the patch to fix this issue.

1. When headset is plugged, the this_enabling will keep true during FM Radio enabling.
2. If the headset have any unplugging/plugging behavior, ignoring it and marked this._isAntennaStateDebouncing as true.
3. Gaia calls mozFMRadio.enabled in updateFreqUI to finish enabling process. If there had any unplugging/plugging behavior in 2, forcing calling this._updateAntennaState() to check according to the current antenna state.

Besides the debouncing, I also found enable/disable FMRadio and Audio rounting at the same time are easily generate pop up noise. For this, I separate the control timing for these two. Can you please review it and give any feedback. Thanks.

Comment 11

[Vincent Liu[:vliu]]

Attachment: WIP_V1 r=Justin Lebar

Hi Justin,

Adjust the wrong Flags for Comment 10.

Comment 12

[Vincent Liu[:vliu]]

Attachment: WIP_V1-gaia r=Justin Lebar

Hi Justin,

This patch is the modification for the gaia part. I think we don't need window._previousFMRadioState to remember FM Radio state during enabling.

Comment 13

[Vincent Liu[:vliu]]

For the behavior in Comment 4, I will file a bug to follow up.

Comment 14

[Justin Lebar (not reading bugmail)]

Comment on attachment 686999 [details] [diff] [review]
WIP_V1 r=Justin Lebar

(BTW, we don't usually ask for review on "WIP" ("work in progress") patches.  In this case, I think it's just a nomenclature issue; these appear to be ready for review, so they're not works in progress.)

>diff --git a/dom/fm/nsIFMRadio.idl b/dom/fm/nsIFMRadio.idl
>+    /**
>+     * Enable Audio Rounting for FM radio.
>+     */
>+    void soundEnable();
>+ 
>+    /**
>+     * Disable Audio Rounting for FM radio.
>+     */
>+    void soundDisable();

I don't think you actually need to modify this interface, but if you do, you
need to update its IID.  (I'd also want to nit on the method names and comments
if we kept this.)

>diff --git a/dom/fm/DOMFMRadioParent.jsm b/dom/fm/DOMFMRadioParent.jsm
>--- a/dom/fm/DOMFMRadioParent.jsm
>+++ b/dom/fm/DOMFMRadioParent.jsm
>@@ -141,16 +144,31 @@
>     this._updateChannelWidth(CHANNEL_WIDTH_100KHZ);
>   },
> 
>   _updateAntennaState: function() {
>     let antennaState = FMRadio.isAntennaAvailable;
> 
>     if (antennaState != this._antennaAvailable) {
>       this._antennaAvailable = antennaState;
>+      if (this._enabling) {
>+        /**
>+         * During FM Radio enabling, ignoring any antenna state updating.
>+         */
>+        this._isAntennaStateDebouncing = true;
>+        return;
>+      }
>+      ppmm.broadcastAsyncMessage("DOMFMRadio:antennaChange", { });
>+      return;
>+    }
>+
>+    if (!this._isAntennaStateDebouncing) {
>+      /**
>+       * We need to force updating antenna stat again to get current state.
>+       */
>       ppmm.broadcastAsyncMessage("DOMFMRadio:antennaChange", { });
>     }

It took me a while to figure out what you did here, but now I think I understand:

* If _updateAntennaState() is caled and the antenna state has changed, we fire
  an antennaChange event, unless we're enabling, in which case we do nothing.

* If _updateAntennaState() is called and the antenna state has not changed, we
  fire an antennaChange event if we're not debouncing.

This is confusing behavior which can lead to errors in the code.  For example,
if someone calls _updateAntennaState() when the antenna hasn't changed state,
we'll hit this new |!debouncing| case and fire an extra antennaChange DOM
event.

There's another problem here, which is that code on the web will be able to
observe the fact that this._antennaAvailable changes before it gets an
antennaChange event (because web code can call getAntennaState).  That will
rightly appear to be a bug in B2G.

A better thing to do, I think, would be to avoid setting this._antennaAvailable
while we're enabling the radio.  Then when the radio is finally enabled, we call
_updateAntennaState, which sends the antennaChange event, if appropriate.

But more generally, I do not understand why we want to suppress antennaChange
events while the radio is enabling.  This feels like a hack.

> Even the headset had a long time in a inserted state, the unexpected
> FM_RADIO_OPERATION_ENABLE reply still happens at the time when I unplugged
> it.

Do you mean that you always see an FM_RADIO_OPERATION_ENABLE event when the
headphones are unplugged?  If so, this is likely something to be fixed in
GonkFMRadio, not in the JS code.

>@@ -331,20 +349,23 @@
>       return;
>     }
> 
>     this._enabling = true;
>     let self = this;
> 
>     FMRadio.addEventListener("enabled", function on_enabled() {
>       debug("FM Radio is enabled!");
>-      self._enabling = false;
> 
>       FMRadio.removeEventListener("enabled", on_enabled);
> 
>+      if (self._antennaAvailable) {
>+        FMRadio.soundEnable();
>+      }

Instead of modifying the nsIFMRadio interface, you can use the nsIAudioManager
interface directly, with something like:

    Cc["@mozilla.org/telephony/audiomanager;1"]
      .getService(nsIAudioManager)
      .fmRadioAudioEnabled = true;

However, I don't understand why this code is needed in the first place.
Comment 10 says:

> Besides the debouncing, I also found enable/disable FMRadio and Audio
> rounting at the same time are easily generate pop up noise. For this, I
> separate the control timing for these two.

I don't understand what separating the control timing means.

I'm totally in favor of fixing loud popping noises, but if these changes are
separate from the changes needed to fix the sound going through the phone's
speakers, it might be helpful if you could present them as a separate patch,
and perhaps as a separate bug, since otherwise it's not always clear which
changes are to fix which problems.

>@@ -417,17 +442,24 @@
>         // this message is sync
>         return {
>           lower: FM_BANDS[self._currentBand].lower / 1000,   // in MHz
>           upper: FM_BANDS[self._currentBand].upper / 1000,   // in MHz
>           channelWidth: self._currentWidth / 1000            // in MHz
>         };
>       case "DOMFMRadio:getPowerState":
>         // this message is sync
>-        return self._isEnabled;
>+        {
>+          this._enabling = false;

By moving the |this._enabling = false| out of the on_enabled() listener above
and into here, the radio is in the "enabling" state until a child calls
getPowerState.  That does not seem correct to me.

Perhaps a simple reason I am skeptical of this is: Even if a child process
always calls DOMFMRadio:getPowerState soon after on_enabled(), in normal
operation, we need to guarantee that this will work correctly if the child
process crashes, or if there is no child process alive at the time.

Another reason I don't think this is correct is: Any child process can call
DOMFMRadio:getPowerState at any point in time.  Suppose a child process calls
DOMFMRadio:getPowerState immediately after you set this._enabling to true.  In
this case, this patch doesn't accomplish what you intended.

In general I'm not convinced that the approach here is correct.  If you're not
sure how best to fix this bug, could you try explaining again what the problem
that you observe is, so I can try to suggest a solution?  I'm afraid I don't
quite understand from your previous comments.

Comment 15

[Alan Huang]

Attachment: Using mutex to prevent race condition between main/radio thread

I used mutex to prevent race condition between main/radio thread in GonkFMRadio.cpp

Also, I found in DOMFMRadioParent.jsm, there's potential bug caused by FMRadio power state inconsistency. (in _disableFMRadio and callback added in _enableFMRadio)

Comment 17

[Michael Wu [:mwu]]

Comment on attachment 689049 [details] [diff] [review]
Using mutex to prevent race condition between main/radio thread

The user of the hal fm radio api should be careful about waiting for the radio to finishing initializing before doing anything. There can be multiple radio backend implementations but there's only one user of the backend so the right place to fix this is in the user.

Comment 18

[Alan Huang]

(In reply to Michael Wu [:mwu] from comment #17)
> Comment on attachment 689049 [details] [diff] [review]
> Using mutex to prevent race condition between main/radio thread
> 
> The user of the hal fm radio api should be careful about waiting for the
> radio to finishing initializing before doing anything. There can be multiple
> radio backend implementations but there's only one user of the backend so
> the right place to fix this is in the user.

Hi Michael,
Due to the race condition in hal fm radio, user of these API cannot even get correct FM radio state (on/off) through IsFMRadioOn(), ...etc. This makes user cannot know whether radio's initialization is finished or not. So I think cannot only be fixed by user of these API. We also need to fix the race condition in hal fm radio.

Comment 19

[Lawrence Mandel [:lmandel] (use needinfo)]

This is enough of an edge case that we can ship v1 with this limitation (as noted in the description). Moving to basecamp- as per platform triage.

Comment 20

[Deepa Subramanian]

Unable to play radio after the headset is unplugged. Reproduced on Unagi device Build ID: 20130125070201 using the december 5th kernel v 1.0.0.0-Prerelease.

Comment 21

[William Hsu [:whsu]]

Hi, all,

Sorry to jump in.
I tried to reproduce this case. But I cannot reproduce it now.
Make it as fixed. If this problem happened again, please reopen it.
Thanks for your help!

The following are my test environment.
* Hardware: unagi
* Firefox OS: mozilla-b2g18_v1_0_1-unagi-eng(2013-03-10-07-02-03)
* Mercurial-Information:
  Gecko revision="a0eb57759a92"
  Gaia revision="72a2e37d17f6"
* Git:
  Gecko revision="f42cd79f6036df3f102fcdb59ff1ab6944305000"
  Gaia revision="b4d644dd5ea79070479a9aa1b57e2e05a6442eee"


Best Regards,
William

Comment 22

[William Hsu [:whsu]]

Reproduced this bug. Reopen it.

* Reproduction build:(Mozilla-central-unagi/2013-04-11-03-05-40)
  - Mercurial-Information:
    + Gecko revision="2949e808ed33"
    + Gaia revision="7afb3dd04527"
  - Git-Information:
    + Gecko revision="512a13dbf89ac26655c8a153d376cadee92a6ef4"
    + Gaia revision="79ccd192e70f99feb9a10e6e83dd8de0a4971160"

Comment 24

[Andrew Stole [:astole]]

I can see a similar issue that appears to be the same root cause. 

Description:
After exiting the FM Radio app and opening the music app, the music is played through the phone speaker even with the headphones plugged into the phone.

Repro Steps:
1) Updated Buri to BuildID: 20140114004002
2) Open FM Radio app 
3) Plug in the headphones
4) Change the volume and scroll to a different radio station
5) Unplug the headphones 
6) Press the home button
7) Launch the music app
8) Plug in the headphones
9) Play a song

Comment 25

[No-Jun Park [:njpark]]

I found a similar, but slightly different steps for this bug:

Repro Steps:
1. Update Buri to BuildID   20140318160201
2. Open FM Radio app with headphone plugged
3. Listen to radio
4. Stop the radio by pressing the stop button
5. Unplug headphone
6. Exit the radio app

Expected:
Phone should not have sound

Actual:
Phone emits radio static sound even after exiting the radio app after turning it off

Comment 26

[Alan Huang]

I'm currently not working on this. Reset to default assignee first.

Comment 27

[BMO Automation]

Firefox OS is not being worked on