1081493 - keytone is disable in particular situation

Status: RESOLVED WONTFIX

(Firefox OS Graveyard :: AudioChannel, defect)

Description

[jingmei.zhang]

[Blocking Requested - why for this release]:

steps to reproduce the issue:
1.make a call
2.recieve a call and answer the call
3.hand up both call

after steps 3,the keytone is disable in keypad.

Comment 1

[jingmei.zhang]

we can reproduce the issue both in 1.3&1.4.but in 2.0,there is no such issue.
when following steps 1,2,3,we find such Abnormal in audioflinger:

V/AudioFlinger(  101): start(4096), calling pid 108 session 113
V/AudioFlinger(  101): ? => ACTIVE (4096) on thread 0xb8672020
V/AudioFlinger(  101): setParameters(): io 0, keyvalue sprd_voip_start=true, calling pid 101
V/AudioFlinger(  101): signal playback thread
V/AudioFlinger(  101): thread 0xb5452008 type 0 TID 307 waking up
W/AudioFlinger(  101): Thread AudioOut_2 cannot connect to the power manager service
E/AudioFlinger(  101): no wake lock to update!
V/AudioFlinger(  101): anticipated start
V/AudioFlinger(  101): setParameters(): io 2, keyvalue routing=1, calling pid 101
V/AudioFlinger(  101): ThreadBase::setParameters() routing=1
V/AudioFlinger(  101): setParameters(): io 2, keyvalue routing=1, calling pid 101
V/AudioFlinger(  101): ThreadBase::setParameters() routing=1
V/AudioFlinger(  101): setParameters(): io 2, keyvalue routing=1, calling pid 101
V/AudioFlinger(  101): ThreadBase::setParameters() routing=1
V/AudioFlinger(  101): setParameters(): io 2, keyvalue routing=1, calling pid 101
V/AudioFlinger(  101): ThreadBase::setParameters() routing=1
V/AudioFlinger(  101): setParameters(): io 2, keyvalue routing=1, calling pid 101
V/AudioFlinger(  101): ThreadBase::setParameters() routing=1
V/AudioFlinger(  101): createTrack() sessionId: 114
V/AudioFlinger(  101): createTrack() lSessionId: 114
V/AudioFlinger(  101): AUDIO_OUTPUT_FLAG_FAST denied: isTimed=0 sharedBuffer=0x0 frameCount=0 mFrameCount=1280 format=1 isLinear=1 channelMask=0x1 sampleRate=48000 mSampleRate=44100 hasFastMixer=0 tid=1606 fastTrackAvailMask=0xfe
V/AudioFlinger(  101): Track constructor name 4097, calling pid 676
V/AudioFlinger(  101): acquiring 114 from 676
V/AudioFlinger(  101):  added new entry for 114
V/AudioFlinger(  101): start(4097), calling pid 676 session 114
V/AudioFlinger(  101): ? => ACTIVE (4097) on thread 0xb86710b8
V/AudioFlinger(  101): signal playback thread
W/AudioFlinger(  101): Thread AudioOut_2 cannot connect to the power manager service
E/AudioFlinger(  101): no wake lock to update!
V/AudioFlinger(  101): stop(4097), calling pid 676
V/AudioFlinger(  101): not stopping/stopped => stopping/stopped (4097) on thread 0xb5452008
V/AudioFlinger(  101): releasing 114 from 676
V/AudioFlinger(  101):  decremented refcount to 0
V/AudioFlinger(  101): purging stale effects
V/AudioFlinger(  101): presentationComplete() mPresentationCompleteFrames 0 framesWritten 779520
V/AudioFlinger(  101): presentationComplete() reset: mPresentationCompleteFrames 786576 audioHalFrames 7056
V/AudioFlinger(  101): presentationComplete() mPresentationCompleteFrames 786576 framesWritten 780800
V/AudioFlinger(  101): presentationComplete() mPresentationCompleteFrames 786576 framesWritten 782080
V/AudioFlinger(  101): presentationComplete() mPresentationCompleteFrames 786576 framesWritten 783360
V/AudioFlinger(  101): presentationComplete() mPresentationCompleteFrames 786576 framesWritten 784640
V/AudioFlinger(  101): presentationComplete() mPresentationCompleteFrames 786576 framesWritten 785920
V/AudioFlinger(  101): presentationComplete() mPresentationCompleteFrames 786576 framesWritten 787200
V/AudioFlinger(  101): presentationComplete() session 114 complete: framesWritten 787200
V/AudioFlinger(  101): removeTracks_l removing track on session 114
V/AudioFlinger(  101): remove track (4097) and delete from mixer

we start a track 4096 for the first call,and a track 4097 for the second call.when the call ended,we could only find track 4097 is removed.
then when we press the key in the keypad,the sound is looked on as a AUDIO_STREAM_VOICE_CALL.

Comment 2

[jingmei.zhang]

hi Vance,can you help to assign to the owner?
This is a really critical issue for us.

Thank you!!!

Comment 3

[helloarvin]

Hi Dominic,

The issue can be reproduced with the 100% rate and belongs to be functional broken. Could you please help check the serious issue based on the above analysis?

Thanks a lot.

Comment 4

[shawn ku [:sku]]

Hi Wayne:
 Please help check this issue to see anything wrong regarding audio.

Thanks!!
Shawn

Comment 5

[Wayne Chen [:xwaynec]]

Attachment: bug1081493_log.txt

After STR, I found that device will always set output to headset when user wanna launch keypad tone.
Maybe communication app owner can take a look first.

01-17 01:29:28.610 D/AudioPolicyManagerBase(   88): setOutputDevice() output 1 device 1 delayMs 0
01-17 01:29:28.610 V/AudioPolicyManagerBase(   88): setOutputDevice() setting same device 1 or null device for output 1
01-17 01:29:28.610 D/AudioPolicyManagerBase(   88): setOutputDevice() output 1 device 0 delayMs 290
01-17 01:29:28.610 V/AudioPolicyManagerBase(   88): setOutputDevice() setting same device 0 or null device for output 1
01-17 01:29:28.650 D/AudioPolicyManagerBase(   88): setOutputDevice() output 1 device 2 delayMs 0
01-17 01:29:28.650 V/AudioPolicyManagerBase(   88): setOutputDevice() routing=2
01-17 01:29:28.780 D/AudioPolicyManagerBase(   88): setOutputDevice() output 1 device 0 delayMs 290
01-17 01:29:28.780 V/AudioPolicyManagerBase(   88): setOutputDevice() setting same device 0 or null device for output 1
01-17 01:29:28.800 D/AudioPolicyManagerBase(   88): setOutputDevice() output 1 device 1 delayMs 0
01-17 01:29:28.890 V/AudioPolicyManagerBase(   88): setOutputDevice() routing=1
01-17 01:29:28.890 D/AudioPolicyManagerBase(   88): setOutputDevice() output 1 device 0 delayMs 290
01-17 01:29:28.890 V/AudioPolicyManagerBase(   88): setOutputDevice() setting same device 0 or null device for output 1

Comment 6

[jingmei.zhang]

hi Wayne:

  for the issue you mentioned in comment5,I think it has something to do with the issue I mentioned in comment1,that is while I hand up the two calls,only one of the two audio tracks is removed.The reasonable result is that both of the audio tracks should be removed while the phone is handed up,is it?

Comment 7

[Wayne Chen [:xwaynec]]

hi jingmei,

I'm not so sure. After hand up 2 calls, I dump media.audio_policy but there is no refcount remained. 
However, it still have same issue.


Outputs dump:
- Output 1 dump:
 Sampling rate: 44100
 Format: 1
 Channels: 00000003
 Latency: 145
 Flags 00000000
 Devices 00000001
 Stream volume refCount muteCount
 00     1.000     00       00
 01     1.000     00       00
 02     1.000     00       00
 03     1.000     00       00
 04     1.000     00       00
 05     1.000     00       00
 06     -1.000     00       00
 07     1.000     00       00
 08     0.004     00       00
 09     0.002     00       00
 10     0.004     00       00

Sincerely,
Wayne

Comment 8

[Wayne Chen [:xwaynec]]

Sorry for typo in comment 5. 

After STR, I found that device will always set output to *earpiece* when user wanna launch keypad tone.
Maybe communication app owner can take a look first.

Comment 9

[jingmei.zhang]

(In reply to Wayne Chen [:xwaynec] from comment #8)
> Sorry for typo in comment 5. 
> 
> After STR, I found that device will always set output to *earpiece* when
> user wanna launch keypad tone.
> Maybe communication app owner can take a look first.

I think the audio track that is left after the two call can help to explain why device will always set output to *earpiece*.
So Wayne,can you help to check if something wrong in audioflinger to prevent the audiotrack from removing??

Comment 10

[Wayne Chen [:xwaynec]]

Attachment: bug1081493.txt

hi aknow,

as offline talk, please help check phonestate in 2nd call comming.

05-08 00:27:33.861 W/audio_hw_primary(   89): adev_set_mode, mode=2
05-08 00:28:04.151 W/audio_hw_primary(   89): adev_set_mode, mode=0
05-08 00:28:04.201 W/audio_hw_primary(   89): adev_set_mode, mode=2
05-08 00:28:18.551 W/audio_hw_primary(   89): adev_set_mode, mode=0

Comment 11

[Dominic Kuo [:dkuo]]

Looks like an audio channel issue and gecko devs are already helping on this.

Comment 12

[Wayne Chen [:xwaynec]]

Hi Etienne,

I found an audio track is created when 2nd call is comming. I think it's a waiting tone. (The waiting tone maybe is 'telephony' channel type?)
In this STR, the waiting tone will not be killed even though user finish call.
Could you give some comment for this? thanks


AudioMixer tracks: 00000001
Output thread 0xd603f8 tracks
   Name  Clien Typ Fmt Chn mask   Session Buf  S M F SRate LeftV RighV  Serv       User       Main buf   Aux Buf
   00000 00085 000 001 0x00000003 00012   0851 6 0 0 44100 04096 04096  0x00395653 0x00396913 0x00d6b298 0x00000000
Output thread 0xd603f8 active tracks
   Name  Clien Typ Fmt Chn mask   Session Buf  S M F SRate LeftV RighV  Serv       User       Main buf   Aux Buf

Sincerely,
Wayne

Comment 13

[Wayne Chen [:xwaynec]]

by the way, this issue in v1.3t

Comment 14

[Gabriele Svelto [:gsvelto] (PTO)]

I don't have a v1.3t build currently so it might take me a bit to investigate this bug. The suggestion in comment 12 that this might be caused by the waiting tone sounds reasonable, I'll try to verify it as soon as I have a working Tarako again.

Comment 15

[Wayne Chen [:xwaynec]]

Hi Gabriele,

v1.4 also has same issue if it's convenient for you to get dolphin.

Comment 16

[Gabriele Svelto [:gsvelto] (PTO)]

(In reply to Wayne Chen [:xwaynec] from comment #15)
> v1.4 also has same issue if it's convenient for you to get dolphin.

I have both so hardware availability is not a problem, it's just that I don't have a build environment ready for those branches, I'll need to set one up to reproduce this.

Comment 17

[Wayne Chen [:xwaynec]]

I tried to remove playWaitingTone(call) and it can't be reproduce. So the track is kept by waiting tone. BTW, it can't be reproduce in v2.0, I think maybe already have solution?

Thanks


diff --git a/apps/callscreen/js/calls_handler.js b/apps/callscreen/js/calls_handler.js
index 3d3875c..4726c5e 100644
--- a/apps/callscreen/js/calls_handler.js
+++ b/apps/callscreen/js/calls_handler.js
@@ -241,7 +241,7 @@ var CallsHandler = (function callsHandler() {
     }

     CallScreen.showIncoming();
-    playWaitingTone(call);
+    //playWaitingTone(call);
   }

Comment 18

[Gabriele Svelto [:gsvelto] (PTO)]

I've checked a bit what are the differences between 1.4 and 2.0 and they're not really much. Bug 1029979 and bug 1039199 have both been fixed on 2.0 but not on 1.4. It might be worth checking both of them to see if they fix the problem here.

Comment 19

[jingmei.zhang]

(In reply to Gabriele Svelto [:gsvelto] from comment #18)
> I've checked a bit what are the differences between 1.4 and 2.0 and they're
> not really much. Bug 1029979 and bug 1039199 have both been fixed on 2.0 but
> not on 1.4. It might be worth checking both of them to see if they fix the
> problem here.

hi Gabriele，I have merged both patches and tested in my locale,but the issue still exist.

Comment 20

[Gabriele Svelto [:gsvelto] (PTO)]

(In reply to jingmei.zhang from comment #19)
> hi Gabriele，I have merged both patches and tested in my locale,but the issue
> still exist.

OK, I'll try to reproduce it here. Note that if the issue is still there with both patches applied it might be that we're hitting a problem on the gecko side.

Comment 21

[Gabriele Svelto [:gsvelto] (PTO)]

Quick update, I haven't had time to look at this again due to our deadlines. I'll try to look at it again ASAP.

Comment 22

[Gabriele Svelto [:gsvelto] (PTO)]

Unfortunately I hadn't had time to look at this and I don't think I'll have before all work on v2.2 is done. Since this is an old issue I'm not sure if it's still worth pursuing. If it's still a problem please NI me again and I'll try to have a look.

Comment 23

[BMO Automation]

Firefox OS is not being worked on