Closed Bug 981885 Opened 6 years ago Closed 6 years ago

[B2G][Bluetooth] No audio notification on "call waiting" call

Categories

(Firefox OS Graveyard :: Bluetooth, defect)

ARM
Gonk (Firefox OS)
defect
Not set

Tracking

(tracking-b2g:backlog, b2g-v1.3 affected, b2g-v1.3T affected, b2g-v1.4 affected)

RESOLVED FIXED
tracking-b2g backlog
Tracking Status
b2g-v1.3 --- affected
b2g-v1.3T --- affected
b2g-v1.4 --- affected

People

(Reporter: sarsenyev, Assigned: scheng)

References

Details

(Whiteboard: permafail, [CR 647237], [ETA:4/25])

Attachments

(1 file)

Attached file log31014.txt
Prerequisites:
FFOS is connected to Bluetooth headset 

Repro Steps:
1) Update a Buri to BuildID: 20140307040203
2) Receive a phone call to FFOS device and answer by tapping the headphone's call
3) When the call is establish make another call to the FFOS headset Bluetooth device

Actual:
A visual notification appears on the FFOS screen, but no audio incoming call sound can be heard on the "call waiting" call

Expected:
The devices receives audio and visual notification on the second incoming call

1.4 Environmental Variables:
Device: Buri 1.4 MOZ
BuildID: 20140307040203
Gaia: 04eb7996543f114133d1367f834a4d88b68c60ac
Gecko: b0e7f63c2138
Version: 30.0a1
Firmware Version: v1.2-device.cfg

Notes:
Audio can be heard on the first incoming call only

Repro frequency: 100%
https://moztrap.mozilla.org/manage/case/6697/
See attached: logcat
The issue reproduces on 1.3 
No audio "notification" when the incoming call

1.3 Environmental Variables:
Device: Buri 1.3 MOZ
BuildID: 20140306004002
Gaia: 8aed4fafbaeb86d6884d31ce7d3cbeb87bcbf837
Gecko: 3d2d84d52141
Version: 28.0
Firmware Version: v1.2-device.cfg
Does this reproduce on 1.1?
Keywords: qawanted
The audio notification (a 'Du' sound) is heard without BT headset but not heard when BT headset is connected. ni? audio team Star.

Star, does audio driver mix the audio notification into bluetooth SCO audio path?
Flags: needinfo?(scheng)
(In reply to Jason Smith [:jsmith] from comment #2)
> Does this reproduce on 1.1?
I don't think this bug has been handled before. It looks like audio HAL related.
(In reply to Shawn Huang [:shuang] [:shawnjohnjr] from comment #4)
> (In reply to Jason Smith [:jsmith] from comment #2)
> > Does this reproduce on 1.1?
> I don't think this bug has been handled before. It looks like audio HAL
> related.

ok - so that means this is not a regression.
Keywords: qawanted
The waiting system tone is belong as "MEDIA" type. I am investigating weather the "MEDIA" stream  can be routed to SOC in audio policy HAL or not.
Flags: needinfo?(scheng)
Whiteboard: burirun1.4-1 → burirun1.4-1, burirun1.4-2
In another device - Nexus4, I can duplicate it. But I am not sure weather the audio routing is correct or not.

Hi, Michael

I check the log, the call waiting tone is routed to "low-latency-playback bt-sco". It should be right. The log is below: Could you help me to check? 
Thanks

[1] ringtone 
I/AudioManager(  179): [star] SetPhoneState aState 1 -> [star] PHONE_STATE_RINGTONE
I/AudioStream( 1218): [star] AudioStream::Init stream type 2 -> [star] CUBEB_STREAM_TYPE_RING

D/audio_hw_primary(  173): out_set_parameters: enter: usecase(1: low-latency-playback) kvpairs: routing=2
D/audio_hw_primary(  173): out_set_parameters: exit: code(1)
D/audio_hw_primary(  173): start_output_stream: enter: usecase(1: low-latency-playback) devices(0x2)
D/audio_hw_primary(  173): select_devices: out_snd_device(2: speaker) in_snd_device(0: none)
D/audio_hw_primary(  173): enable_snd_device: sending audio calibration for snd_device(2) acdb_id(14)
E/audio_hw_primary(  173): [star] enable_snd_device: snd_device(2: speaker)
E/audio_hw_primary(  173): [star] enable_audio_route: enter: usecase(1)
E/audio_hw_primary(  173): [star]enable_audio_route: apply mixer path: low-latency-playback
E/audio_hw_primary(  173): [star] device id 14 sample rate 48000
D/audio_hw_primary(  173): start_output_stream: exit
D/audio_hw_primary(  173): adev_set_parameters: enter: bt_samplerate=8000
D/audio_hw_primary(  173): adev_set_parameters: exit with code(-2)
D/audio_hw_primary(  173): out_set_parameters: enter: usecase(1: low-latency-playback) kvpairs: routing=2
D/audio_hw_primary(  173): out_set_parameters: exit: code(1)

[2] in call
I/AudioManager(  179): [star] SetPhoneState aState 2 -> [star] PHONE_STATE_IN_CALL

D/audio_hw_primary(  173): out_set_parameters: enter: usecase(1: low-latency-playback) kvpairs: routing=32
D/audio_hw_primary(  173): select_devices: out_snd_device(10: bt-sco-headset) in_snd_device(0: none)
D/audio_hw_primary(  173): disable_audio_route: reset mixer path: low-latency-playback
D/audio_hw_primary(  173): disable_snd_device: snd_device(2: speaker)
D/audio_hw_primary(  173): enable_snd_device: sending audio calibration for snd_device(10) acdb_id(22)
E/audio_hw_primary(  173): [star] enable_snd_device: snd_device(10: bt-sco-headset)
E/audio_hw_primary(  173): [star] enable_audio_route: enter: usecase(1)
E/audio_hw_primary(  173): [star]enable_audio_route: apply mixer path: low-latency-playback bt-sco
D/audio_hw_primary(  173): start_voice_call: enter
D/audio_hw_primary(  173): select_devices: out_snd_device(10: bt-sco-headset) in_snd_device(24: bt-sco-mic)
D/audio_hw_primary(  173): enable_snd_device: snd_device(10: bt-sco-headset) is already active
D/audio_hw_primary(  173): enable_snd_device: sending audio calibration for snd_device(24) acdb_id(21)
E/audio_hw_primary(  173): [star] enable_snd_device: snd_device(24: bt-sco-mic)
E/audio_hw_primary(  173): [star] enable_audio_route: enter: usecase(5)
E/audio_hw_primary(  173): [star]enable_audio_route: apply mixer path: voice-call bt-sco
D/audio_hw_primary(  173): out_set_parameters: exit: code(2)
D/audio_hw_primary(  173): out_standby: enter: usecase(1: low-latency-playback)
D/audio_hw_primary(  173): stop_output_stream: enter: usecase(1: low-latency-playback)
D/audio_hw_primary(  173): disable_audio_route: reset mixer path: low-latency-playback bt-sco
D/audio_hw_primary(  173): stop_output_stream: exit: status(0)
D/audio_hw_primary(  173): out_standby: exit

[3] waiting call tone
I/AudioStream( 1218): [star] AudioStream::Init stream type 1 -> CUBEB_STREAM_TYPE_SYSTEM

D/audio_hw_primary(  173): out_set_parameters: enter: usecase(1: low-latency-playback) kvpairs: routing=32
D/audio_hw_primary(  173): out_set_parameters: exit: code(2)
D/audio_hw_primary(  173): start_output_stream: enter: usecase(1: low-latency-playback) devices(0x20)
D/audio_hw_primary(  173): select_devices: out_snd_device(10: bt-sco-headset) in_snd_device(0: none)
D/audio_hw_primary(  173): enable_snd_device: snd_device(10: bt-sco-headset) is already active
E/audio_hw_primary(  173): [star] enable_audio_route: enter: usecase(1)
E/audio_hw_primary(  173): [star]enable_audio_route: apply mixer path: low-latency-playback bt-sco
E/audio_hw_primary(  173): [star] device id 14 sample rate 48000
D/audio_hw_primary(  173): start_output_stream: exit
Flags: needinfo?(mvines)
Flags: needinfo?(mvines) → needinfo?(bhargavg1)
Flags: needinfo?(bhargavg1)
Whiteboard: burirun1.4-1, burirun1.4-2 → burirun1.4-1, burirun1.4-2,[CR 647237]
Duplicate of this bug: 995986
Blocks: 984663
Eric,

Can you please review the logs pasted? Please help with next steps.
Flags: needinfo?(echou)
Vasanth/Bhargav -- can you also please address Star's questions in comment 7.
Flags: needinfo?(vasanth)
Flags: needinfo?(bhargavg1)
Whiteboard: burirun1.4-1, burirun1.4-2,[CR 647237] → permafail, [CR 647237]
(In reply to Preeti Raghunath(:Preeti) from comment #9)
> Eric,
> 
> Can you please review the logs pasted? Please help with next steps.

Preeti,

The logs star pasted were for Bhargav and we're still looking forward to his response.
Flags: needinfo?(echou)
Assignee: nobody → scheng
Got it. It's a mismatch between GeckoBluetooth and Bluedroid. 

From below adb logs during this scenario,
<<
I/GeckoBluetooth( 207): UpdatePhoneCIND: [2] state 10 => BTHF: active[1] held[0] state[5]
E/bt-btif ( 207): phone_state_change: Incorrect new ringing call state
>>

Here 5 in "state[5]" corresponds to BTHF_CALL_STATE_WAITING.
But I see the switch statement in phone_state_change(), btif_hf.c [1] never handles BTHF_CALL_STATE_WAITING. So this fails.

For same scenario (incoming call during live call), android framework sends BTHF_CALL_STATE_INCOMING again and bluedroid internally converts it to BTA_AG_CALL_WAIT_RES here [2]

Gecko should do similar to android framework, since we don't have control over bluedroid?

[1] https://www.codeaurora.org/cgit/quic/la/platform/external/bluetooth/bluedroid/tree/btif/src/btif_hf.c/?h=b2g_kk_3.5#n1007
[2] https://www.codeaurora.org/cgit/quic/la/platform/external/bluetooth/bluedroid/tree/btif/src/btif_hf.c/?h=b2g_kk_3.5#n940
Flags: needinfo?(vasanth)
Flags: needinfo?(bhargavg1)
blocking-b2g: --- → 1.4?
Star,

Do we need anything else from Vasanth?
Flags: needinfo?(scheng)
CS blocker - so moving to 1.4+
blocking-b2g: 1.4? → 1.4+
Hi, Shawn

Could you provide more information about Comment 12? 

Thanks
Flags: needinfo?(scheng) → needinfo?(shuang)
(In reply to vasanth from comment #12)
> Got it. It's a mismatch between GeckoBluetooth and Bluedroid. 
> 
> From below adb logs during this scenario,
> <<
> I/GeckoBluetooth( 207): UpdatePhoneCIND: [2] state 10 => BTHF: active[1]
> held[0] state[5]
> E/bt-btif ( 207): phone_state_change: Incorrect new ringing call state
> >>
> 
> Here 5 in "state[5]" corresponds to BTHF_CALL_STATE_WAITING.
> But I see the switch statement in phone_state_change(), btif_hf.c [1] never
> handles BTHF_CALL_STATE_WAITING. So this fails.
> 
> For same scenario (incoming call during live call), android framework sends
> BTHF_CALL_STATE_INCOMING again and bluedroid internally converts it to
> BTA_AG_CALL_WAIT_RES here [2]
> 
> Gecko should do similar to android framework, since we don't have control
> over bluedroid?
> 
> [1]
> https://www.codeaurora.org/cgit/quic/la/platform/external/bluetooth/
> bluedroid/tree/btif/src/btif_hf.c/?h=b2g_kk_3.5#n1007
> [2]
> https://www.codeaurora.org/cgit/quic/la/platform/external/bluetooth/
> bluedroid/tree/btif/src/btif_hf.c/?h=b2g_kk_3.5#n940

This had been fixed in Bug 993288. Star can you apply patches of Bug 993288? But i'm not sure why Comment 12 is related to this bug. Both buri and Nexus 4 can reproduce this bug, and Buri uses Bluez.
I don't understand even if audio path switches to BT_SCO and it's related to bluetooth? I think call waiting tone shall be mixed into SCO.
Flags: needinfo?(shuang)
(In reply to Shawn Huang [:shuang] [:shawnjohnjr] from comment #17)
> But i'm not sure why Comment 12 is related to this bug. 

Shawn, This are the only errors I see in my qrd 8x26 device during this scenario. Aren't you seeing these errors in a device with bluedroid?
I'm not sure about same issue with bluez though.
The volume (after calling computeVolume() )is set as 0 besides voice & SCO. The log as below:

stream 0 -> VOICE_CALL
stream 6 -> BLUETOOTH_SCO

D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume stream 0 device 32 index 0 output 2 
D/AudioPolicyManagerBase( 1182): [star]checkAndSetVolume() cannot set stream 0 volume with force use = 3 for comm
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume stream 1 device 32 index 0 output 2
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume volume 0
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume stream 2 device 32 index 0 output 2
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume volume 0
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume stream 3 device 32 index 0 output 2
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume volume 0
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume stream 4 device 32 index 0 output 2
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume volume 0
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume stream 5 device 32 index 0 output 2
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume volume 0
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume stream 6 device 32 index 10 output 2 -> 
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume volume 1070596096
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume stream 7 device 32 index 0 output 2
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume volume 0
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume stream 8 device 32 index 0 output 2
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume volume 0
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume stream 9 device 32 index 0 output 2
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume volume 0
E/AudioPolicyManagerBase( 1182): [star] handleIncallSonification stream_strategy 0
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume stream 1 device 32 index 0 output 2
D/AudioPolicyManagerBase( 1182): [star] checkAndSetVolume volume 0


We should use "Telephony" audio channel type to ensure we can hear "waiting tone" with SCO device in call.
Depends on: 984498
We will plumb audiochannel type from AudioContext to mediastreamgraph (for audio back-end) in Bug 984498. After finishing it, we can use 'telephony' type for waiting tone. So I mark this bug depend on bug 984498.
Depends on: 997701
No longer depends on: 984498
Depend on: Bug 997701

Because we need to use 'telephony' AudioChannelType for busy tone & waiting tone. After finishing solving Bug 997701, we can solve this issue (Bug 981885) as well.
Whiteboard: permafail, [CR 647237] → permafail, [CR 647237], [ETA:4/25]
Retriage - this is up for consideration to be punted, as this is a feature request.

mvines - can we consider removing this from the QC CS queue?
blocking-b2g: 1.4+ → 1.4?
Flags: needinfo?(mvines)
What is the LoE to fix this bug after bug 997701 (v1.3+) lands?
Flags: needinfo?(mvines)
(In reply to Michael Vines [:m1] [:evilmachines] from comment #23)
> What is the LoE to fix this bug after bug 997701 (v1.3+) lands?

Star - Can you answer this?
Flags: needinfo?(scheng)
No longer blocks: 984663
(In reply to Jason Smith [:jsmith] from comment #24)
> (In reply to Michael Vines [:m1] [:evilmachines] from comment #23)
> > What is the LoE to fix this bug after bug 997701 (v1.3+) lands?
> 
> Star - Can you answer this?


If the patches of bug 984498 & bug 997701 are both landed, it can solve this bug. I think the effort is low. And I am trying to resolve test case fail caused by my patch of bug 984498.
Flags: needinfo?(scheng)
Thanks Star. I think we should aim to get this in to v1.4.  It'll make the product much better for BT users, and we all know how long the OTA upgrades take.
(In reply to Michael Vines [:m1] [:evilmachines] from comment #26)
> Thanks Star. I think we should aim to get this in to v1.4.  It'll make the
> product much better for BT users, and we all know how long the OTA upgrades
> take.

Looks like landings in bug 984498 & bug 997701 should take care of this bug. I'll mark the dependency here and not block on this issue.
Inder,

Can we please have this issue tested once bug 984498 and bug 997701 have landed? 

We want to ensure that the issue is actually fixed with landing bug 984498 and bug 997701.
Flags: needinfo?(ikumar)
> 
> Can we please have this issue tested once bug 984498 and bug 997701 have
> landed? 
> 
> We want to ensure that the issue is actually fixed with landing bug 984498
> and bug 997701.

Moving the ni to Vasanth.
Preeti -- Just to confirm, this doesn't block our CS but i think Vasanth can help here.
Vasanth -- can you please verify once those fixes are uplifted to v1.4.
Flags: needinfo?(ikumar) → needinfo?(vasanth)
(In reply to Preeti Raghunath(:Preeti) from comment #28)
> Can we please have this issue tested once bug 984498 and bug 997701 have
> landed? 

Sure Preeti. ni me again when they are landed in V1.4
Flags: needinfo?(vasanth)
Backlog bug 981885. Banking on bug 984498 and bug 997701 to fix the issue.

Vasanth,

Bugs landed.
blocking-b2g: 1.4? → backlog
Flags: needinfo?(vasanth)
(In reply to Preeti Raghunath(:Preeti) from comment #31)
> Backlog bug 981885. Banking on bug 984498 and bug 997701 to fix the issue.
> 
> Vasanth,
> 
> Bugs landed.

Preeti, I see bug 984498 is not landed in V1.4 yet (landed, backed out and not landed again)
Will monitor & test once that is landed.
Hi Vasanth,

(In reply to vasanth from comment #32)
> (In reply to Preeti Raghunath(:Preeti) from comment #31)
> > Backlog bug 981885. Banking on bug 984498 and bug 997701 to fix the issue.
> > 
> > Vasanth,
> > 
> > Bugs landed.
> 
> Preeti, I see bug 984498 is not landed in V1.4 yet (landed, backed out and
> not landed again)
> Will monitor & test once that is landed.

bug 984498 has landed for a few days. Please test again. Thank you.
(In reply to Eric Chou [:ericchou] [:echou] from comment #33)
> bug 984498 has landed for a few days. Please test again. Thank you.

It's working as expected in V1.4. Able to hear busy/call waiting tone for new incoming call when another call is in progress. Thanks!
Flags: needinfo?(vasanth)
That's great. Thanks for testing, Vasanth.

Close as resolve fixed per comment 34 and add bug 984498 to the see also list.
See Also: → 984498
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
We have exactly the same issue.

Our modification is below:
AudioPolicyManagerBase::computeVolume

    //roy: modify for set BluetoothSCO volume max
    if (stream == AudioSystem::BLUETOOTH_SCO) {
        ALOGE("BT SCO use max value");
        return 1.0;
    }
and we found sometimes we will miss the BTA_AG_HF_CMD_CCWA cmd.
bta_ag_cmd.c
        case BTA_AG_CALL_WAIT_RES:
            //roy to support ccwa by default 
            //if (p_scb->ccwa_enabled)
            {
                bta_ag_send_result(p_scb, code, p_result->data.str, 0);
            }
            bta_ag_send_call_inds(p_scb, p_result->result);
            break;

Roy
blocking-b2g: backlog → ---
You need to log in before you can comment on or make changes to this bug.