1008849 - [Tarako][FM] FM does not work after unplugging and plugging the earphone when the screen is locked.

Status: VERIFIED FIXED

(Firefox OS Graveyard :: Gaia::FMRadio, defect)

Description

[Bingqing Li]

Environment:
-----------------------------------------------------
Gaia      fabc8154b31178515795b0a32068257fd5a16269
Gecko     https://hg.mozilla.org/releases/mozilla-b2g28_v1_3t/rev/a500e34d8819
BuildID   20140511164002
Version   28.1
ro.build.version.incremental=eng.cltbld.20140511.204401
ro.build.date=Sun May 11 20:44:08 EDT 2014


Steps to reproduce:
-----------------------------------------------------
1. Launch FM
2. Lock the screen
3. Unplug the earphone
4. Plug the earphone
5. Unlock the screen


Actual result:
------------------------------------------------------
FM does not work at all.
No response after tapping on the buttons.


Additional info:
------------------------------------------
 Need to restart the devices to recover from it.

Comment 1

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

This sounds like a common use case scenario.  I do this often when transporting my own devices.  Nom'ing.

Comment 2

[Steven Yang [:styang]]

Hi Pin, could you help to check this issue? thanks.

Comment 3

[Pin Zhang [:pzhang] (inactive)]

I debugged and found no FM_RADIO_OPERATION_ENABLE event is received after call mozilla::hal::EnableFMRadio by following the steps described in common 0, so something in gonk is wrong in this case.

@Steven, can you take a look?

Comment 4

[StevenLee[:slee]]

Hi Pin,

Can you test whether earphone plug/unplug works? You can launch music app and test whether it is OK. If it's not OK, it should not be the problem of FM radio. BTW, you may need to ask Marco to help this problem.

Comment 5

[Pin Zhang [:pzhang] (inactive)]

(In reply to StevenLee[:slee] from comment #4)
> Hi Pin,
> 
> Can you test whether earphone plug/unplug works? You can launch music app
> and test whether it is OK. If it's not OK, it should not be the problem of
> FM radio. BTW, you may need to ask Marco to help this problem.

@bli tested, earphone works on music app. 

@marco, could you take a look?

Comment 6

[Bingqing Li]

Attachment: slog

Comment 7

[Bingqing Li]

Attachment: logcat

Comment 8

[Vincent Liu[:vliu]]

@wayne, can you take a look on this? Thanks

Comment 9

[Marco Chen [:mchen]]

Hi Wayne,

Could you help it first? If everything I can help please let me know.

Comment 10

[Xinhe Yan]

Jesse,
I found this log after plug earphone
<4>0[   57.958793] trout_fm _trout_fm_open-44 -- start open fm module...
<4>0[   57.958859] trout_fm _trout_fm_open-53 -- The system is suspending!

Can you check this?

Comment 11

[Wayne Chen [:xwaynec]]

After tracing the log, In the moment of pluging out headset, audio driver has some error message, I think the problem is in that.


05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): changeRefCount() stream 3, count 0
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getNewDevice() selected device 0
05-12 17:25:36.025 D/AudioPolicyManagerBase(   90): setOutputDevice() output 1 device 0 delayMs 290
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): setOutputDevice() setting same device 0 or null device for output 1
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): setForceUse() usage 1, config 0, mPhoneState 0
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getNewDevice() selected device 0
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getDeviceForStrategy() from cache strategy 4, device 2
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getDeviceForStrategy() strategy 4, device 2
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getDeviceForStrategy() from cache strategy 1, device 1
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getDeviceForStrategy() strategy 1, device 1
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getDeviceForStrategy() from cache strategy 2, device 2
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getDeviceForStrategy() strategy 2, device 2
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getDeviceForStrategy() from cache strategy 0, device 2
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getDeviceForStrategy() strategy 0, device 2
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getDeviceForStrategy() from cache strategy 3, device 2
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getDeviceForStrategy() strategy 0, device 2
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getDeviceForStrategy() strategy 3, device 2
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getDeviceForStrategy() strategy 0, device 2
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getDeviceForStrategy() strategy 1, device 1
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getDeviceForStrategy() strategy 2, device 2
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getDeviceForStrategy() strategy 0, device 2
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getDeviceForStrategy() strategy 3, device 2
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getDeviceForStrategy() strategy 4, device 2
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): getDeviceForStrategy() strategy 5, device 0
05-12 17:25:36.025 D/AudioPolicyManagerBase(   90): setOutputDevice() output 1 device 0 delayMs 0
05-12 17:25:36.025 V/AudioPolicyManagerBase(   90): setOutputDevice() setting same device 0 or null device for output 1
05-12 17:25:36.035 V/AudioPolicyManagerBase(   90): releaseOutput() 1
05-12 17:25:36.195 W/audio_hw_primary(   90): warning:-32, (wait error: hw 0x46640 app 0x4c900 avail 0x140
05-12 17:25:36.195 W/audio_hw_primary(   90): : Unknown error: -32)
05-12 17:25:36.195 W/audio_hw_primary(   90): do_output_standby.mode:0 
05-12 17:25:36.215 I/audio_hw_primary(   90): select_devices_signal starting...
05-12 17:25:36.215 I/audio_hw_primary(   90): select_devices_signal finished.
05-12 17:25:36.215 W/audio_hw_primary(   90): open s_tinycard in
05-12 17:25:36.215 W/audio_hw_primary(   90): open s_tinycard successfully
05-12 17:25:36.215 I/audio_hw_primary(   90): Changing devices: 0x00000002
05-12 17:25:36.215 I/audio_hw_primary(   90): Set 'HeadPhone Function'.0 to 0
05-12 17:25:36.215 I/audio_hw_primary(   90): Set 'Earpiece Function'.0 to 0
05-12 17:25:36.215 I/audio_hw_primary(   90): Set 'Mic Function'.0 to 0
05-12 17:25:36.215 I/audio_hw_primary(   90): Set 'HP Mic Function'.0 to 0
05-12 17:25:36.215 I/audio_hw_primary(   90): Set 'Line Function'.0 to 0
05-12 17:25:36.215 I/audio_hw_primary(   90): Changing devices, mask: 0x00004002
05-12 17:25:36.215 I/audio_hw_primary(   90): Set 'Speaker Function'.0 to 1
05-12 17:25:36.215 I/vb_effect(   90): s_cur_devices(0x00000002)
05-12 17:25:36.215 I/vb_effect(   90): profile is Handsfree, ret=0

Comment 12

[Vincent Liu[:vliu]]

(In reply to Wayne Chen [:xwaynec] from comment #11)
> After tracing the log, In the moment of pluging out headset, audio driver
> has some error message, I think the problem is in that.
> 
> 
> setting same device 0 or null device for output 1
> 05-12 17:25:36.035 V/AudioPolicyManagerBase(   90): releaseOutput() 1
> 05-12 17:25:36.195 W/audio_hw_primary(   90): warning:-32, (wait error: hw
> 0x46640 app 0x4c900 avail 0x140

@Wayne, did you mean the error log highlighted here? I tried plug in/out many times without out Lock/Unlock the screen, but the FMRadio still works well. I am not sure if it is the root cause.

I added the log in GonkFMRadio.cpp. When the step 3(Plug the earphone) runs, it fails on 

/* This runs on the main thread but most of the
 * initialization is pushed to the radio thread. */
void
EnableFMRadio(const hal::FMRadioSettings& aInfo)
{
  ... 
  mozilla::ScopedClose fd(open("/dev/radio0", O_RDWR));
  if (fd < 0) {
    HAL_LOG(("Unable to open radio device"));
    return;
  } 
  ...
}

For this fail point, I think SPRD should take effort on it. Thanks

Comment 13

[Vincent Liu[:vliu]]

(In reply to Vincent Liu[:vliu] from comment #12)

> I added the log in GonkFMRadio.cpp. When the step 3(Plug the earphone) runs,
> it fails on 
> 

Sorry for the wrong info. |Plug the earphone| should be in step 4, and it means plug in the earphone.

Comment 14

[Jesse]

I will take a look.

Comment 15

[Jesse]

I have fixed the bug on our side.

The root cause is that our FM driver checks whether the system is suspending or not before opening FM. Actually we do want to open FM in early suspending status like this case.

Comment 16

[Jesse]

  Notice the flaw in GonkFMRadio.

  mozilla::ScopedClose fd(open("/dev/radio0", O_RDWR));
  if (fd < 0) {
    HAL_LOG(("Unable to open radio device"));
    return;
  }

  We should notify opening failed event here.


  mozilla::ScopedClose fd(open("/dev/radio0", O_RDWR));
  if (fd < 0) {
    HAL_LOG(("Unable to open radio device"));

    hal::FMRadioOperationInformation info;
    info.operation() = hal::FM_RADIO_OPERATION_ENABLE;
    info.status() = hal::FM_RADIO_OPERATION_STATUS_FAIL;
    hal::NotifyFMRadioStatus(info);

    return;
  }

Comment 17

[Vincent Liu[:vliu]]

(In reply to Jesse from comment #16)
>   Notice the flaw in GonkFMRadio.
> 
>   mozilla::ScopedClose fd(open("/dev/radio0", O_RDWR));
>   if (fd < 0) {
>     HAL_LOG(("Unable to open radio device"));
>     return;
>   }
> 
>   We should notify opening failed event here.
> 
> 
>   mozilla::ScopedClose fd(open("/dev/radio0", O_RDWR));
>   if (fd < 0) {
>     HAL_LOG(("Unable to open radio device"));
> 
>     hal::FMRadioOperationInformation info;
>     info.operation() = hal::FM_RADIO_OPERATION_ENABLE;
>     info.status() = hal::FM_RADIO_OPERATION_STATUS_FAIL;
>     hal::NotifyFMRadioStatus(info);
> 
>     return;
>   }

In GonkFMRadio.cpp:EnableFMRadio(), it seems we have many system calls which doesn't notify by fail situation. @wayne, would you please file another bug for this? Thanks.

Comment 18

[[:fabrice] Fabrice Desré]

(In reply to Jesse from comment #15)
> I have fixed the bug on our side.
> 
> The root cause is that our FM driver checks whether the system is suspending
> or not before opening FM. Actually we do want to open FM in early suspending
> status like this case.

Hi Jesse,

I'm marking this one fixed since it's fixed on gonk.

Comment 19

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

Gaia      917174ee3812a43758bf43f7ba5f9416dcdb2ca8
Gecko     https://hg.mozilla.org/releases/mozilla-b2g28_v1_3t/rev/7296746ab908
BuildID   20140519014003
Version   28.1
ro.build.version.incremental=eng.cltbld.20140519.052855
ro.build.date=Mon May 19 05:29:01 EDT 2014
Tarako