Closed
Bug 1006356
Opened 11 years ago
Closed 11 years ago
[hamachi][2.0]Not possible to change volume level after voice call
Categories
(Firefox OS Graveyard :: Gaia::System, defect)
Tracking
(blocking-b2g:1.3T+, b2g-v1.3 unaffected, b2g-v1.3T fixed, b2g-v1.4 fixed, b2g-v2.0 fixed)
Tracking | Status | |
---|---|---|
b2g-v1.3 | --- | unaffected |
b2g-v1.3T | --- | fixed |
b2g-v1.4 | --- | fixed |
b2g-v2.0 | --- | fixed |
People
(Reporter: zrzut01, Assigned: gerard-majax)
References
Details
(Keywords: regression, Whiteboard: [systemsfe][partner-blocker][sprd311363][sprd311363])
Attachments
(4 files)
User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:29.0) Gecko/20100101 Firefox/29.0 (Beta/Release)
Build ID: 20140421221237
Steps to reproduce:
1. Set some volume levels for ringtones and etc.
2. Make a voice call.
3. Finish voice call.
Actual results:
From now it is impossible to change volume control i.e. for ringtones or FM Radio when every time volume buttons are pressed the voice call volume control appears.
Expected results:
It should be possible to change volume control for other types of sound after finish a voice call.
Found on:
Alcatel One Touch Fire (T-mobile Poland)
B2G version: 2.0.0.0-prerelease master
Platform version: 32.0a1
Build Identifier: 20140505160203
Git commit info: 2014-05-05 09:01:02 e8a08a3f
Assignee | ||
Comment 2•11 years ago
|
||
I'm reproducing this on Nexus S and Desire Z at least.
Component: Gaia → Gaia::Dialer
Comment 3•11 years ago
|
||
I'm reproducing this on Geeksphone Peak (nightly build image from http://downloads.geeksphone.com/peak/master/latest_master.html)
And I can add that when I'm listening music after this issues, when I lock my phone music stop. Don't know if this is related, but it occured at the same time.
(In reply to romain from comment #3)
> I'm reproducing this on Geeksphone Peak (nightly build image from
> http://downloads.geeksphone.com/peak/master/latest_master.html)
>
> And I can add that when I'm listening music after this issues, when I lock
> my phone music stop. Don't know if this is related, but it occured at the
> same time.
Same on hamachi, I think that it is related problem.
OS: All → Gonk (Firefox OS)
Hardware: All → ARM
Assignee | ||
Comment 5•11 years ago
|
||
Reproduced on Flame.
Status: UNCONFIRMED → NEW
blocking-b2g: --- → 2.0?
Component: Gaia::Dialer → RIL
Ever confirmed: true
Keywords: regression
Updated•11 years ago
|
Keywords: regressionwindow-wanted
Comment 6•11 years ago
|
||
Recently we found some weird call audio behaviour (e.g. bug 1005498 and bug 1002538) which is triggered by bug 999334. We provided a patch on bug 1005498 that resolves bug 1005498 and bug 1002538.
When I noticed this issue, I first thought that this issue could be the same one as above. However, even I applied the patch on 1005498, the issue is still. Also, RIL code doesn't touch volume control, so it's not obvious to me that it's a RIL issue. I guess we would need to check recent changes on volume control or audio management.
Updated•11 years ago
|
QA Contact: ckreinbring
Comment 7•11 years ago
|
||
B2G-Inbound regression window from Buri 2.0
No repro
Build ID: 20140429020207
Gecko: https://hg.mozilla.org/integration/b2g-inbound/rev/be5b6fda11f9
Gaia: d9cb98243113558e4581c6bfcb6515ae6b088620
Platform Version: 32.0a1
Firmware Version: V1.2-device.cfg
Repro
Build ID: 20140429023207
Gecko: https://hg.mozilla.org/integration/b2g-inbound/rev/2607b6b60561
Gaia: 08cdbbbf5c35f7002388b920d4fb75570f2ae0d1
Platform Version: 32.0a1
Firmware Version: V1.2-device.cfg
Old Gaia / New Gecko - OK
New Gaia / Old Gecko - Fail
https://github.com/mozilla-b2g/gaia/compare/d9cb98243113558e4581c6bfcb6515ae6b088620...08cdbbbf5c35f7002388b920d4fb75570f2ae0d1
Keywords: regressionwindow-wanted
Comment 8•11 years ago
|
||
Comment 9•11 years ago
|
||
The window above can't be right. The patch called out here is dealing with contacts import, which has nothing to do with this bug.
Keywords: regressionwindow-wanted
Comment 10•11 years ago
|
||
Tinderbox regression window on Buri 2.0 mozilla RIL
No repro
Build ID: 20140429044712
Gecko: https://hg.mozilla.org/mozilla-central/rev/400a31da59a9
Gaia: 725a23802708eb70e3d7e8a2ce7179adbac806e4
Platform Version: 32.0a1
Firmware Version: V1.2-device.cfg
Repro
Build ID: 20140429093609
Gecko: https://hg.mozilla.org/mozilla-central/rev/34a7215c5d85
Gaia: 1892ba3a857f7e9cd1d2a0cf1c87481f3dcaca2c
Platform Version: 32.0a1
Firmware Version: V1.2-device.cfg
Gaia push log: https://github.com/mozilla-b2g/gaia/compare/725a23802708eb70e3d7e8a2ce7179adbac806e4...1892ba3a857f7e9cd1d2a0cf1c87481f3dcaca2c
Keywords: regressionwindow-wanted
Comment 11•11 years ago
|
||
comment 10 isn't really answering my question on the request in comment 9 - did you check to see if the window there was correct or not?
Keywords: regressionwindow-wanted
Assignee | ||
Comment 12•11 years ago
|
||
(In reply to Hsin-Yi Tsai [:hsinyi] from comment #6)
> Recently we found some weird call audio behaviour (e.g. bug 1005498 and bug
> 1002538) which is triggered by bug 999334. We provided a patch on bug
> 1005498 that resolves bug 1005498 and bug 1002538.
>
> When I noticed this issue, I first thought that this issue could be the same
> one as above. However, even I applied the patch on 1005498, the issue is
> still. Also, RIL code doesn't touch volume control, so it's not obvious to
> me that it's a RIL issue. I guess we would need to check recent changes on
> volume control or audio management.
Thanks, then it may be a gaia system bug. Taking.
Assignee: nobody → lissyx+mozillians
Status: NEW → ASSIGNED
Component: RIL → Gaia::System
Target Milestone: --- → 2.0 S1 (9may)
Updated•11 years ago
|
Whiteboard: [systemsfe]
Updated•11 years ago
|
blocking-b2g: 2.0? → 2.0+
Comment 14•11 years ago
|
||
I retested the b2g-inbound window, the Tinderbox window provided previously is correct. The new b2g-inbound window is:
Last working
B2G-Inbound Environmental Variables:
Device: Buri Master MOZ
BuildID: 20140429014311
Gaia: 5e09ffe399cce7575011408fea4b7b43b3dcc148
Gecko: 5f256979dacc
Version: 32.0a1
Firmware Version: v1.2-device.cfg
First Broken
B2G-Inbound Environmental Variables:
BuildID: 20140429020207
Gaia: d9cb98243113558e4581c6bfcb6515ae6b088620
Gecko: be5b6fda11f9
Version: 32.0a1
Firmware Version: v1.2-device.cfg
Gecko/Gaia Swap Test
First Broken Gecko / Last Working Gaia: Issue does not reproduce
Gaia: 5e09ffe399cce7575011408fea4b7b43b3dcc148
Gecko: be5b6fda11f9
First Broken Gaia / Last Working Gecko: Issue Reproduces
Gaia: d9cb98243113558e4581c6bfcb6515ae6b088620
Gecko: 5f256979dacc
Gaia Pushlog:
https://github.com/mozilla-b2g/gaia/compare/5e09ffe399cce7575011408fea4b7b43b3dcc148...d9cb98243113558e4581c6bfcb6515ae6b088620
Updated•11 years ago
|
Keywords: regressionwindow-wanted
Comment 15•11 years ago
|
||
This is either caused by bug 997701 or bug 1000047.
Etienne - Which bug caused this regression?
Flags: needinfo?(etienne)
Assignee | ||
Comment 16•11 years ago
|
||
(In reply to Jason Smith [:jsmith] from comment #15)
> This is either caused by bug 997701 or bug 1000047.
>
> Etienne - Which bug caused this regression?
I'll check both.
Assignee | ||
Comment 17•11 years ago
|
||
I cannot reproduce anymore once I locally revert merge commit 3617fa6b6e5e2e3c7a198227d27a12bca830ff0a (bug 997701).
Comment 18•11 years ago
|
||
I don't think that the gaia patch in bug 997701 is causing the issue seen here, I think it's more likely that it's caused by the new Gecko functionality that patch uses (namely creating an AudioContext with a specific channel). I think it's more likely that the issue originated from bug 984498 where that functionality was introduced in Gecko.
Assignee | ||
Comment 19•11 years ago
|
||
(In reply to Gabriele Svelto [:gsvelto] from comment #18)
> I don't think that the gaia patch in bug 997701 is causing the issue seen
> here, I think it's more likely that it's caused by the new Gecko
> functionality that patch uses (namely creating an AudioContext with a
> specific channel). I think it's more likely that the issue originated from
> bug 984498 where that functionality was introduced in Gecko.
It seems you are right: I added some debug to TonePlayer, and it seems to correctly switch from normal to telephony channel and then back to normal.
Assignee | ||
Comment 20•11 years ago
|
||
$ adb logcat -v threadtime | egrep TonePlayer
05-08 13:12:13.382 3399 3399 E GeckoConsole: Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:243 in tp_setChannel: TonePlayer: setChannel(normal => telephony) from: tp_setChannel@app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:243:5
05-08 13:12:13.382 3399 3399 E GeckoConsole: Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:48 in tp_trashAudio: TonePlayer: trashAudio(normal)
05-08 13:12:13.392 3399 3399 E GeckoConsole: Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:43 in tp_ensureAudio: TonePlayer: ensureAudio: new AudioContext(telephony)
05-08 13:12:21.042 3399 3399 E GeckoConsole: Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:243 in tp_setChannel: TonePlayer: setChannel(telephony => normal) from: tp_setChannel@app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:243:5
05-08 13:12:21.042 3399 3399 E GeckoConsole: Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:48 in tp_trashAudio: TonePlayer: trashAudio(telephony)
05-08 13:12:21.042 3399 3399 E GeckoConsole: Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:43 in tp_ensureAudio: TonePlayer: ensureAudio: new AudioContext(normal)
05-08 13:12:21.092 3399 3399 E GeckoConsole: Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:48 in tp_trashAudio: TonePlayer: trashAudio(normal)
05-08 13:12:21.102 3399 3399 E GeckoConsole: Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:243 in tp_setChannel: TonePlayer: setChannel(null => normal) from: tp_setChannel@app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:243:5
05-08 13:12:21.102 3399 3399 E GeckoConsole: Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:48 in tp_trashAudio: TonePlayer: trashAudio(null)
05-08 13:12:21.102 3399 3399 E GeckoConsole: Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:43 in tp_ensureAudio: TonePlayer: ensureAudio: new AudioContext(normal)
05-08 13:12:21.542 3399 3399 E GeckoConsole: Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:243 in tp_setChannel: TonePlayer: setChannel(null => normal) from: tp_setChannel@app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:243:5
05-08 13:12:21.542 3399 3399 E GeckoConsole: Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:48 in tp_trashAudio: TonePlayer: trashAudio(null)
05-08 13:12:21.542 3399 3399 E GeckoConsole: Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:43 in tp_ensureAudio: TonePlayer: ensureAudio: new AudioContext(normal)
Assignee | ||
Comment 21•11 years ago
|
||
SoundManager in the system app is getting locked into 'telephony' channel.
Assignee | ||
Comment 22•11 years ago
|
||
At https://github.com/mozilla-b2g/gaia/blob/master/apps/system/js/sound_manager.js#L306, we find a comment stating:
> // XXX: This work should be removed
> // once we could get telephony channel change event
> // https://bugzilla.mozilla.org/show_bug.cgi?id=819858
So it may be related ...
Depends on: 819858
Assignee | ||
Comment 23•11 years ago
|
||
currentChannel in SoundManager is not getting updated when call is finished: we are waiting for a mozChromeEvent named 'audio-channel-changed', but we are only getting three 'visible-audio-channel-changed'. When the call is first placed, we get one 'audio-channel-changed'.
Assignee | ||
Comment 24•11 years ago
|
||
Re-checked, with and without bug 997701:
- with, we get audio-channel-changed and visible-audio-channel-changed when we hang up
- without, we get three visible-audio-channel-changed when we hang up.
Comment 25•11 years ago
|
||
Bouncing into 1.4? triage since the regressing cause is going to be present on 1.3, 1.4, & 2.0 (although bug 984498 hasn't been uplifted yet).
Vance - This bug is a regression from a cert blocker in bug 984498. Can you find out if the followup here to the cert blocker is also a cert blocker?
blocking-b2g: 2.0+ → 1.4?
Flags: needinfo?(etienne) → needinfo?(vchen)
Yes, this is a cert blocker
Flags: needinfo?(vchen)
Updated•11 years ago
|
blocking-b2g: 1.4? → 1.3+
Whiteboard: [systemsfe] → [systemsfe][cert]
Assignee | ||
Comment 27•11 years ago
|
||
Alive, please review this. It fixes the exposed bug, but:
- I have no idea of the consequences of this change
- I'm not sure if it's normal that we do not get audio-channel-changed but rather visible-audio-channel-changed
- Writing unit tests for this sound_manager seems far from possible, but if you see a way to test this, I'm happy to hear from you :)
Attachment #8419456 -
Flags: review?(alive)
Comment 28•11 years ago
|
||
Thanks for investigating.
But I'd rather to think this is a gecko bug.
Gecko should send audio-channel-changed when the busy tone which is telephony channel terminates any way.
Star, could you confirm?
Flags: needinfo?(scheng)
Comment 29•11 years ago
|
||
Comment 30•11 years ago
|
||
Comment on attachment 8419456 [details] [review]
Link to Github https://github.com/mozilla-b2g/gaia/pull/19070
I tend to grant for v1.3 because it's already too late to fix this in gecko but I'd like gecko guy to fix it in 1.4+.
Attachment #8419456 -
Flags: review?(alive) → review+
Assignee | ||
Comment 31•11 years ago
|
||
(In reply to Alive Kuo [:alive][NEEDINFO!] from comment #30)
> Comment on attachment 8419456 [details] [review]
> Link to Github https://github.com/mozilla-b2g/gaia/pull/19070
>
> I tend to grant for v1.3 because it's already too late to fix this in gecko
> but I'd like gecko guy to fix it in 1.4+.
Thanks. However, I have not tested whether we have this on v1.3. I'll check as soon as I'm in the office :)
Comment 32•11 years ago
|
||
(In reply to Alive Kuo [:alive][NEEDINFO!] from comment #28)
> Thanks for investigating.
> But I'd rather to think this is a gecko bug.
> Gecko should send audio-channel-changed when the busy tone which is
> telephony channel terminates any way.
>
> Star, could you confirm?
I will investigate it.
Flags: needinfo?(scheng)
Comment 33•11 years ago
|
||
(In reply to Star Cheng [:scheng] from comment #32)
> (In reply to Alive Kuo [:alive][NEEDINFO!] from comment #28)
> > Thanks for investigating.
> > But I'd rather to think this is a gecko bug.
> > Gecko should send audio-channel-changed when the busy tone which is
> > telephony channel terminates any way.
> >
> > Star, could you confirm?
>
> I will investigate it.
I have a guess: tone player holds the telephony channel even after call end.
Assignee | ||
Comment 34•11 years ago
|
||
(In reply to Alive Kuo [:alive][NEEDINFO!] from comment #33)
> (In reply to Star Cheng [:scheng] from comment #32)
> > (In reply to Alive Kuo [:alive][NEEDINFO!] from comment #28)
> > > Thanks for investigating.
> > > But I'd rather to think this is a gecko bug.
> > > Gecko should send audio-channel-changed when the busy tone which is
> > > telephony channel terminates any way.
> > >
> > > Star, could you confirm?
> >
> > I will investigate it.
>
> I have a guess: tone player holds the telephony channel even after call end.
Alive, I'm not sure this is what TonePlayer does, as exposed in comment 20: it seems to switch back to normal channel correctly. Maybe you mean there is a race condition then ?
Comment 35•11 years ago
|
||
(In reply to Alexandre LISSY :gerard-majax from comment #34)
> (In reply to Alive Kuo [:alive][NEEDINFO!] from comment #33)
> > (In reply to Star Cheng [:scheng] from comment #32)
> > > (In reply to Alive Kuo [:alive][NEEDINFO!] from comment #28)
> > > > Thanks for investigating.
> > > > But I'd rather to think this is a gecko bug.
> > > > Gecko should send audio-channel-changed when the busy tone which is
> > > > telephony channel terminates any way.
> > > >
> > > > Star, could you confirm?
> > >
> > > I will investigate it.
> >
> > I have a guess: tone player holds the telephony channel even after call end.
>
> Alive, I'm not sure this is what TonePlayer does, as exposed in comment 20:
> it seems to switch back to normal channel correctly. Maybe you mean there is
> a race condition then ?
I mean system should know the switch back to normal by audio-channel-changed event, but as you described we don't get it. Am I misunderstanding you?
Assignee | ||
Comment 36•11 years ago
|
||
Digging this up again, I noticed that there was multiple calls to TonePlayer.setChannel():
(1) one from https://github.com/mozilla-b2g/gaia/blob/master/apps/callscreen/js/calls_handler.js#L311
(2) one from https://github.com/mozilla-b2g/gaia/blob/master/shared/js/dialer/keypad.js#L237
The call from (1) is done when the call screen window is closing, while the call (2) is performed when hiding the keypad.
Now, what I'm seeing is that (2) comes before (1), and that this makes Gecko thinking that the channel is still visible. Removing call (2) fixes the issue.
Flags: needinfo?(etienne)
Assignee | ||
Comment 37•11 years ago
|
||
In Gecko, mCurrentHigherChannel is correctly switched first, but then never switched back:
I/Gecko (12746): [-----] AudioChannel: new mCurrentHigherChannel=0
I/Gecko (12746): [-----] AudioChannel: new mCurrentVisibleHigherChannel=0
I/Gecko (12746): [-----] AudioChannel: new mCurrentHigherChannel=4
I/Gecko (12746): [-----] AudioChannel: new mCurrentVisibleHigherChannel=4
I/Gecko (12746): [-----] AudioChannel: new mCurrentVisibleHigherChannel=0
I/Gecko (12746): [-----] AudioChannel: new mCurrentVisibleHigherChannel=-1
I/Gecko (12746): [-----] AudioChannel: new mCurrentVisibleHigherChannel=0
Assignee | ||
Comment 38•11 years ago
|
||
In AudioChannelService, I noticed that when we hang up, the invalid higher value which is stuck to AudioChannel::Telephony comes from: http://dxr.mozilla.org/mozilla-central/source/dom/audiochannel/AudioChannelService.cpp#550
Hacking the indexes from [*2+1] to only [*2] makes the higher value not being changed and "fixing" the issue. I'm wondering whether those indexes are right, or if the issue is that !IsEmpty() is valid.
Flags: needinfo?(paul)
Assignee | ||
Comment 39•11 years ago
|
||
Some more logs at hangup time. This excerpt comes from logcat, and is generated by a call at the very begining of TonePlayer.setChannel():
> console.debug("TonePlayer: AudioChannel setChannel([" + (typeof this._channel) + "]" + this._channel + " => [" + (typeof channel) + "]" + channel + "). Request from: " + (new Error()).stack);
We see a first TonePlayer.setChannel("normal") that comes from keypad.js' visibilitychange handler:
> E/GeckoConsole(20185): Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:249 in tp_setChannel: TonePlayer: AudioChannel setChannel([object]null => [string]normal). Request from: tp_setChannel@app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:249:119
> E/GeckoConsole(20185): kh_init/<@app://callscreen.gaiamobile.org/shared/js/dialer/keypad.js:237:7
> E/GeckoConsole(20185): Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:255 in tp_setChannel: TonePlayer: AudioChannel set to: normal. Request from: tp_setChannel@app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:255:5
> E/GeckoConsole(20185): kh_init/<@app://callscreen.gaiamobile.org/shared/js/dialer/keypad.js:237:7
> E/GeckoConsole(20185): Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:49 in tp_ensureAudio: TonePlayer: AudioContext: ensureAudio(normal) [{"normal":1,"telephony":0}] FROM:tp_ensureAudio@app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:49:5
> E/GeckoConsole(20185): tp_setChannel@app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:259:5
> E/GeckoConsole(20185): kh_init/<@app://callscreen.gaiamobile.org/shared/js/dialer/keypad.js:237:7
Then a second call to TonePlayer.setChannel("normal") coming from calls_handler.js' window closing:
> E/GeckoConsole(20185): Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:249 in tp_setChannel: TonePlayer: AudioChannel setChannel([object]null => [string]normal). Request from: tp_setChannel@app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:249:119
> E/GeckoConsole(20185): closeWindow@app://callscreen.gaiamobile.org/js/calls_handler.js:311:5
> E/GeckoConsole(20185): exitCallScreen@app://callscreen.gaiamobile.org/js/calls_handler.js:305:7
> E/GeckoConsole(20185): onCallsChanged@app://callscreen.gaiamobile.org/js/calls_handler.js:117:7
> E/GeckoConsole(20185): Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:255 in tp_setChannel: TonePlayer: AudioChannel set to: normal. Request from: tp_setChannel@app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:255:5
> E/GeckoConsole(20185): closeWindow@app://callscreen.gaiamobile.org/js/calls_handler.js:311:5
> E/GeckoConsole(20185): exitCallScreen@app://callscreen.gaiamobile.org/js/calls_handler.js:305:7
> E/GeckoConsole(20185): onCallsChanged@app://callscreen.gaiamobile.org/js/calls_handler.js:117:7
> E/GeckoConsole(20185): Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:49 in tp_ensureAudio: TonePlayer: AudioContext: ensureAudio(normal) [{"normal":1,"telephony":0}] FROM:tp_ensureAudio@app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:49:5
> E/GeckoConsole(20185): tp_setChannel@app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:259:5
> E/GeckoConsole(20185): closeWindow@app://callscreen.gaiamobile.org/js/calls_handler.js:311:5
> E/GeckoConsole(20185): exitCallScreen@app://callscreen.gaiamobile.org/js/calls_handler.js:305:7
> E/GeckoConsole(20185): onCallsChanged@app://callscreen.gaiamobile.org/js/calls_handler.js:117:7
One should notice that in both cases, we see "setChannel([object]null => [string]normal)", meaning that this._channel has not been changed.
Assignee | ||
Comment 40•11 years ago
|
||
Prior to landing the callscreen app, the keypad.js was not using a visibilitychange handler as we can check in https://github.com/mozilla-b2g/gaia/blob/e151331f5688d933fad4b9da067ffdd57653b733/apps/communications/dialer/js/keypad.js#L234:
> TonePlayer.init(this._onCall ? 'telephony' : 'normal');
Comment 41•11 years ago
|
||
Hey, nice digging. Not sure what information is needed from me though :/
Flags: needinfo?(etienne)
Assignee | ||
Comment 42•11 years ago
|
||
Etienne, why was the visibilitychange handler added ?
Flags: needinfo?(etienne)
Comment 43•11 years ago
|
||
302 baku on this one, since he wrote the code. What are your thougts on comment 38 ?
Flags: needinfo?(paul) → needinfo?(amarchesini)
Assignee | ||
Comment 44•11 years ago
|
||
I had a closer look at the mChannelCounters behavior. The following log only focuses on the index [9], which seems to be the one triggering the issue.
> I/Gecko ( 287): AudioChannelService::RegisterType: mChannelCounters[9].AppendElement(0); +1
> I/Gecko ( 287): [XXXXX] [IsEmpty] AudioChannel: higher=4, index=4, mChannelCounters[9]
> I/Gecko ( 287): AudioChannelService::UpdateChannelType: mChannelCounters[9].RemoveElement(0); -1
> I/Gecko ( 287): AudioChannelService::RegisterType: mChannelCounters[9].AppendElement(0); +1
> I/Gecko ( 287): AudioChannelService::UpdateChannelType: mChannelCounters[9].RemoveElement(0); -1
> I/Gecko ( 287): AudioChannelService::UpdateChannelType: mChannelCounters[9].AppendElement(0); +1
> I/Gecko ( 287): [XXXXX] [IsEmpty] AudioChannel: higher=4, index=4, mChannelCounters[9]
Assignee | ||
Comment 45•11 years ago
|
||
The latest AppendElement is triggered from http://dxr.mozilla.org/mozilla-central/source/dom/audiochannel/AudioChannelService.cpp#295
The fact that there is no subsequent RemoveElement call displayed means we probably hit the assert.
Assignee | ||
Comment 46•11 years ago
|
||
So I can confirm we can do both call, this is not a problem of maybe leaking something. By hacking with some setTimeout(), I can show that if keypad.js calls setChannel() first, it's NOT triggering the issue.
Comment 47•11 years ago
|
||
> Hacking the indexes from [*2+1] to only [*2] makes the higher value not
> being changed and "fixing" the issue. I'm wondering whether those indexes
> are right, or if the issue is that !IsEmpty() is valid.
No. This seems correct because the index goes from AudioChannel::Normal (0) to
AudioChannel::Publicnotification. We want to have a value from AudioChannelInternalType enum where any audiochannel is foreground and background. Doing index * 2 you obtain a value from AudioChannelInternalType enum. +1 gives you the index for the background channel.
I'm debugging it with a real device. gerard-majax, have you checked if mDeferTelChannelTimer is used?
Telephony channel is not released immediately: there is a timer of 1500ms.
Flags: needinfo?(amarchesini)
Assignee | ||
Comment 48•11 years ago
|
||
(In reply to Andrea Marchesini (:baku) from comment #47)
> > Hacking the indexes from [*2+1] to only [*2] makes the higher value not
> > being changed and "fixing" the issue. I'm wondering whether those indexes
> > are right, or if the issue is that !IsEmpty() is valid.
>
> No. This seems correct because the index goes from AudioChannel::Normal (0)
> to
> AudioChannel::Publicnotification. We want to have a value from
> AudioChannelInternalType enum where any audiochannel is foreground and
> background. Doing index * 2 you obtain a value from AudioChannelInternalType
> enum. +1 gives you the index for the background channel.
>
> I'm debugging it with a real device. gerard-majax, have you checked if
> mDeferTelChannelTimer is used?
> Telephony channel is not released immediately: there is a timer of 1500ms.
I'm checking ths right now. While hacking on the Gaia side, I noticed that sending a setChannel("normal") or setChannel("telephony") from keypad.js did not seems to have an impact: what is important is doing a setChannel, not the payload.
Assignee | ||
Comment 49•11 years ago
|
||
Indeed, mDeferTelChannelTimer is being used and it goes upto the Notify().
Flags: needinfo?(amarchesini)
Assignee | ||
Comment 50•11 years ago
|
||
Hacking to make mDeferTelChannelTimer not used does not help.
Assignee | ||
Comment 52•11 years ago
|
||
(gdb) print *(script.ptr->scriptSource())
$8 = {refs = 1, dataType = js::ScriptSource::DataMissing, data = {uncompressed = {chars = 0x5a5a5a5a <Address 0x5a5a5a5a out of bounds>, ownsChars = 90}, compressed = {raw = 0x5a5a5a5a,
nbytes = 1515870810}}, length_ = 0, filename_ = 0xb0e37080 "app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js", displayURL_ = 0x0, sourceMapURL_ = 0x0,
originPrincipals_ = 0xb0e81904, introductionOffset_ = 0, introducerFilename_ = 0xb0e37080 "app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js",
introductionType_ = 0xb5f9bc5d "scriptElement", sourceRetrievable_ = false, argumentsNotIncluded_ = false, hasIntroductionOffset_ = true}
Assignee | ||
Comment 53•11 years ago
|
||
gdb backtrace shows this is triggering the creation of a new AudioContext:
(gdb) bt
#0 mozilla::dom::AudioChannelService::RegisterType (this=0xab5ab100, aChannel=mozilla::dom::Telephony, aChildID=41856205516, aWithVideo=false)
at ../../../gecko/dom/audiochannel/AudioChannelService.cpp:154
#1 0xb54a2cb0 in RegisterAudioChannelAgent (aWithVideo=false, aChannel=mozilla::dom::Telephony, aAgent=0xabdbc220, this=0xab5ab100) at ../../../gecko/dom/audiochannel/AudioChannelService.cpp:127
#2 mozilla::dom::AudioChannelService::RegisterAudioChannelAgent (this=0xab5ab100, aAgent=0xabdbc220, aChannel=mozilla::dom::Telephony, aWithVideo=<optimized out>)
at ../../../gecko/dom/audiochannel/AudioChannelService.cpp:114
#3 0xb54a187e in mozilla::dom::AudioChannelAgent::StartPlaying (this=0xabdbc220, _retval=0xbed30360) at ../../../gecko/dom/audiochannel/AudioChannelAgent.cpp:127
#4 0xb55ea3d0 in mozilla::dom::AudioDestinationNode::CreateAudioChannelAgent (this=0xadb3cd70) at ../../../../gecko/content/media/webaudio/AudioDestinationNode.cpp:527
#5 0xb55ead42 in mozilla::dom::AudioDestinationNode::AudioDestinationNode (this=0xadb3cd70, aContext=<optimized out>, aIsOffline=<optimized out>, aChannel=mozilla::dom::Telephony,
aNumberOfChannels=0, aLength=0, aSampleRate=0) at ../../../../gecko/content/media/webaudio/AudioDestinationNode.cpp:274
#6 0xb55e9bde in mozilla::dom::AudioContext::AudioContext (this=0xab5b4a10, aWindow=0xae3a08c0, aIsOffline=<optimized out>, aChannel=mozilla::dom::Telephony, aNumberOfChannels=0, aLength=0,
aSampleRate=0) at ../../../../gecko/content/media/webaudio/AudioContext.cpp:97
#7 0xb55e9d32 in mozilla::dom::AudioContext::Constructor (aGlobal=<optimized out>, aChannel=mozilla::dom::Telephony, aRv=<optimized out>)
at ../../../../gecko/content/media/webaudio/AudioContext.cpp:152
#8 0xb5116836 in mozilla::dom::AudioContextBinding::_constructor (cx=0xb06fba20, argc=<optimized out>, vp=0xb2dda130) at AudioContextBinding.cpp:1194
The breakpoint was added in RegisterType. Logging shows that |GetInternalType(aChannel, true);| returned a type of 9 which, to my understanding, matches a telephony channel that is hidden.
Updated•11 years ago
|
Target Milestone: 2.0 S1 (9may) → 2.0 S2 (23may)
Comment 54•11 years ago
|
||
(In reply to Alexandre LISSY :gerard-majax from comment #42)
> Etienne, why was the visibilitychange handler added ?
Since the callscreen is preloaded and hidden, we don't want it to keep and audio channel open when not displayed.
Flags: needinfo?(etienne)
Assignee | ||
Comment 55•11 years ago
|
||
Makes sense. I hacked a bit in the train. For some reason that I have no idea, it seems that using document.hidden I'm not able to reproduce being stuck on the telephony channel: after 1.5sec (like the timer in AudioChannelService?) it switches back correctly to normal channel.
Flags: needinfo?(etienne)
Assignee | ||
Comment 57•11 years ago
|
||
(In reply to Alexandre LISSY :gerard-majax from comment #55)
> Makes sense. I hacked a bit in the train. For some reason that I have no
> idea, it seems that using document.hidden I'm not able to reproduce being
> stuck on the telephony channel: after 1.5sec (like the timer in
> AudioChannelService?) it switches back correctly to normal channel.
It seems like a false positive ; there is something else at play, with document.hidden I'm reproducing the issue again at some point.
Assignee | ||
Comment 59•11 years ago
|
||
Comment on attachment 8421295 [details] [diff] [review]
Test patch
It does not seems to be helping :(
Attachment #8421295 -
Flags: feedback-
Assignee | ||
Comment 61•11 years ago
|
||
So far, my understanding of the issue is the following:
(1) the channel is blocked on telephony because gaia's SoundManager never received any audio-channel-changed event, but rather a visible-audio-channel-changed
(2) AudioChannelService is sending the wrong event because we don't match the condition |(higher != mCurrentHigherChannel)|
(3) this condition is not not matched because |higher| is being reset because we match |!mChannelCounters[index * 2 + 1].IsEmpty()|
(4) we match this !IsEmpty() condition because at some point, TonePlayer is creating a AudioContext as documented by the backtrace provided by comment 53
(5) Hacking [index * 2 + 1] works around the issue, and using gdb we see that the RegisterType() call deduce a |type = 9|, which matches (index=4)*2+1, i.e., a background telephony channel
Andrea, can you backup that the behavior is the one we want ?
Flags: needinfo?(amarchesini)
Assignee | ||
Comment 62•11 years ago
|
||
When the telephony channel is involved, I see two transitions from type 9 to type 8, i.e. telephony hidden to visible:
> I/Gecko ( 4899): AudioChannelService::UpdateChannelType(aChannel=4) :::==> (newType=8 != oldType=9) ?= 1;
> I/Gecko ( 4899): AudioChannelService::UpdateChannelType(aChannel=4) [8].AppendElement();
> I/Gecko ( 4899): AudioChannelService::UpdateChannelType(aChannel=4) [9].RemoveElement();
> I/Gecko ( 4899): AudioChannelService: higher=4 mCurrentHigherChannel=4
Then at the end, one transition is done from type 8 to 9, telephony visible to hidden:
> I/Gecko ( 4899): AudioChannelService::UpdateChannelType(aChannel=4) :::==> (newType=9 != oldType=8) ?= 1;
> I/Gecko ( 4899): AudioChannelService::UpdateChannelType(aChannel=4) [9].AppendElement();
> I/Gecko ( 4899): AudioChannelService::UpdateChannelType(aChannel=4) [8].RemoveElement();
> I/Gecko ( 4899): AudioChannelService: oldHigher=0 higher=4 index=4 (9) users=1
> I/Gecko ( 4899): AudioChannelService: higher=4 mCurrentHigherChannel=4
This is when things are starting to mess up.
Assignee | ||
Comment 63•11 years ago
|
||
Placing a call, then hanging up:
First, with the TonePlayer.setChannel() call in visibilitychange handler in keypad.js:
> I/Gecko ( 8523): AudioChannelService: higher != mCurrentHigherChannel, mCurrentHigherChannel=0 try to notify observer
> I/Gecko ( 8523): AudioChannelService[5]: higher != mCurrentHigherChannel, mCurrentHigherChannel=0 WILL notify observer
> I/Gecko ( 8523): AudioChannelService[5]: visibleHigher != mCurrentVisibleHigherChannel, mCurrentVisibleHigherChannel=0 WILL notify observer
> I/Gecko ( 8523): AudioChannelService: higher != mCurrentHigherChannel, mCurrentHigherChannel=4 try to notify observer
> I/Gecko ( 8523): AudioChannelService[0]: higher != mCurrentHigherChannel, mCurrentHigherChannel=4 WILL notify observer
> I/Gecko ( 8523): AudioChannelService[0]: visibleHigher != mCurrentVisibleHigherChannel, mCurrentVisibleHigherChannel=4 WILL notify observer
> I/Gecko ( 8523): AudioChannelService[0]: visibleHigher != mCurrentVisibleHigherChannel, mCurrentVisibleHigherChannel=0 WILL notify observer
> I/Gecko ( 8523): AudioChannelService[0]: visibleHigher != mCurrentVisibleHigherChannel, mCurrentVisibleHigherChannel=-1 WILL notify observer
> I/Gecko ( 8523): AudioChannelService[5]: visibleHigher != mCurrentVisibleHigherChannel, mCurrentVisibleHigherChannel=0 WILL notify observer
Then, without this call:
> I/Gecko ( 9065): AudioChannelService: higher != mCurrentHigherChannel, mCurrentHigherChannel=0 try to notify observer
> I/Gecko ( 9065): AudioChannelService[5]: higher != mCurrentHigherChannel, mCurrentHigherChannel=0 WILL notify observer
> I/Gecko ( 9065): AudioChannelService[5]: visibleHigher != mCurrentVisibleHigherChannel, mCurrentVisibleHigherChannel=0 WILL notify observer
> I/Gecko ( 9065): AudioChannelService: higher != mCurrentHigherChannel, mCurrentHigherChannel=4 try to notify observer
> I/Gecko ( 9065): AudioChannelService[0]: higher != mCurrentHigherChannel, mCurrentHigherChannel=4 WILL notify observer
> I/Gecko ( 9065): AudioChannelService[0]: visibleHigher != mCurrentVisibleHigherChannel, mCurrentVisibleHigherChannel=4 WILL notify observer
> I/Gecko ( 9065): AudioChannelService: higher != mCurrentHigherChannel, mCurrentHigherChannel=0 try to notify observer
> I/Gecko ( 9065): AudioChannelService[0]: higher != mCurrentHigherChannel, mCurrentHigherChannel=0 WILL notify observer
> I/Gecko ( 9065): AudioChannelService[0]: visibleHigher != mCurrentVisibleHigherChannel, mCurrentVisibleHigherChannel=0 WILL notify observer
> I/Gecko ( 9065): AudioChannelService: higher != mCurrentHigherChannel, mCurrentHigherChannel=-1 try to notify observer
> I/Gecko ( 9065): AudioChannelService[0]: higher != mCurrentHigherChannel, mCurrentHigherChannel=-1 WILL notify observer
> I/Gecko ( 9065): AudioChannelService[0]: visibleHigher != mCurrentVisibleHigherChannel, mCurrentVisibleHigherChannel=-1 WILL notify observer
> I/Gecko ( 9065): AudioChannelService: higher != mCurrentHigherChannel, mCurrentHigherChannel=0 try to notify observer
> I/Gecko ( 9065): AudioChannelService[5]: higher != mCurrentHigherChannel, mCurrentHigherChannel=0 WILL notify observer
> I/Gecko ( 9065): AudioChannelService[5]: visibleHigher != mCurrentVisibleHigherChannel, mCurrentVisibleHigherChannel=0 WILL notify observer
Assignee | ||
Comment 64•11 years ago
|
||
It seems, but I'd need to confirm it further, that NOT doing the TonePlayer.setChannel() FROM keypad.js call WHEN document.hidden is true, then I don't reproduce the issue.
But I still don't understand whatever happens. My latest backtrace shows a visibilitychange with |this=0xab72d340, aChannel=mozilla::dom::Telephony, aChildID=0, aElementHidden=true, aElementWasHidden=false|, which justifies the |!mChannelCounters[index*2+1].IsEmpty()| being true.
Flags: needinfo?(etienne)
Flags: needinfo?(amarchesini)
Assignee | ||
Comment 65•11 years ago
|
||
I did some more testing in the train. In the following,
- ACS stands for AudioChannelService,
- R means RegisterType
- C means UpdateChannelType
- U means UnregisterTypeInterval
- the first digit is the aChildID
- channel is the aChannel value
- type is the result of GetTypeInternal
Then we can check the chain of events when hanging up.
Case where the channel is correctly reset:
> acs.log:05-13 19:38:42.808 16516 16516 I Gecko : [0] ACS:R [channel=4] [type=9]
> acs.log:05-13 19:38:42.808 16516 16516 I Gecko : [0] ACS:C [channel=4] [type: 9 -> 8]
> acs.log:05-13 19:38:43.188 16516 16516 I Gecko : [0] ACS:R [channel=4] [type=9]
> acs.log:05-13 19:38:43.188 16516 16516 I Gecko : [0] ACS:C [channel=4] [type: 9 -> 8]
> acs.log:05-13 19:38:52.968 16516 16516 I Gecko : [0] ACS:C [channel=4] [type: 9 -> 9]
> acs.log:05-13 19:38:58.378 16516 16516 I Gecko : [0] ACS:U [channel=4] [type=9]
Case where it is not:
> acs2.log:05-13 19:40:20.018 16516 16516 I Gecko : [0] ACS:R [channel=4] [type=9]
> acs2.log:05-13 19:40:20.028 16516 16516 I Gecko : [0] ACS:C [channel=4] [type: 9 -> 8]
> acs2.log:05-13 19:40:20.448 16516 16516 I Gecko : [0] ACS:R [channel=4] [type=9]
> acs2.log:05-13 19:40:20.448 16516 16516 I Gecko : [0] ACS:C [channel=4] [type: 9 -> 8]
> acs2.log:05-13 19:40:29.668 16516 16516 I Gecko : [0] ACS:C [channel=4] [type: 9 -> 9]
> acs2.log:05-13 19:40:32.778 16516 16516 I Gecko : [0] ACS:C [channel=4] [type: 9 -> 9]
> acs2.log:05-13 19:40:47.028 16516 16516 I Gecko : [0] ACS:R [channel=4] [type=9]
> acs2.log:05-13 19:40:47.038 16516 16516 I Gecko : [0] ACS:C [channel=4] [type: 9 -> 9]
> acs2.log:05-13 19:40:47.038 16516 16516 I Gecko : [0] ACS:C [channel=4] [type: 9 -> 8]
> acs2.log:05-13 19:40:47.398 16516 16516 I Gecko : [0] ACS:R [channel=4] [type=9]
> acs2.log:05-13 19:40:47.398 16516 16516 I Gecko : [0] ACS:C [channel=4] [type: 9 -> 9]
> acs2.log:05-13 19:40:47.398 16516 16516 I Gecko : [0] ACS:C [channel=4] [type: 9 -> 8]
> acs2.log:05-13 19:40:49.898 16516 16516 I Gecko : [0] ACS:C [channel=4] [type: 9 -> 9]
> acs2.log:05-13 19:40:53.728 16516 16516 I Gecko : [0] ACS:C [channel=4] [type: 9 -> 9]
> acs2.log:05-13 19:40:55.198 16516 16516 I Gecko : [0] ACS:C [channel=4] [type: 9 -> 9]
> acs2.log:05-13 19:40:55.698 16516 16516 I Gecko : [0] ACS:C [channel=4] [type: 9 -> 9]
> acs2.log:05-13 19:40:55.838 16516 16516 I Gecko : [0] ACS:C [channel=4] [type: 9 -> 9]
So what it tells us is that in the correct case, we do the UnregisterTypeInternal, while we seems to never be doing it in the bogus case.
Comment 66•11 years ago
|
||
Hi Star,
Alex has done several analysis and has already had some log here. Could you help with taking a look based on his observation?
Flags: needinfo?(scheng)
Updated•11 years ago
|
status-b2g-v1.3T:
--- → affected
Comment 67•11 years ago
|
||
(In reply to Eric Chou [:ericchou] [:echou] from comment #66)
> Hi Star,
>
> Alex has done several analysis and has already had some log here. Could you
> help with taking a look based on his observation?
Thanks Alex's Digging, you provide more information to this issue.
I found there is another telephony audio channel is registered before SetPhoneState aState as 2 (IN_Call mode). And add some log to trace it. It should be registered in keypad.js. Please see below log:
(telephony audio channel type should be registered in AudioManager::setPhoneSteate())
I/GeckoDump( 177): [star] visibilitychange channel:telephony
I/GeckoDump( 177): [star] tone palyer setChannel - channel:telephony
I/GeckoDump( 177): [star] tone player trashAudio
I/AudioChannelAgent( 177): [star] AudioChannelAgent::StartPlaying
I try to disable the init flow of toneplayer because it should be created while pressing the touch screen of number key of keypad.
https://github.com/mozilla-b2g/gaia/blob/master/shared/js/dialer/keypad.js#L234
comment line 234 ~ line 238
//TonePlayer.init('normal');
//var channel = this._onCall ? 'telephony' : 'normal';
//window.addEventListener('visibilitychange', (function() {
// TonePlayer.setChannel(document.mozHidden ? 'normal' : channel);
//}).bind(this));
Flags: needinfo?(scheng)
Comment 68•11 years ago
|
||
I have a question about this:
https://github.com/mozilla-b2g/gaia/blob/master/apps/callscreen/js/calls_handler.js#L311
I have no idea what the closeWindow() should do. If the function want to close the toneplayer, it seems to use toneplayer.trashAudio() instead of set the audio channel as 'normal'.
Comment 69•11 years ago
|
||
There is another strange point - there are 2 'ringer' audio channel are registered. Please see below. We should only need either.
https://github.com/mozilla-b2g/gaia/blob/master/apps/system/js/dialer_agent.js#L46
http://dxr.mozilla.org/mozilla-central/source/dom/system/gonk/AudioManager.cpp#539
I try to disable the AudioManager part, and it works normally. I will investigate it and check weather the AudioManager part is necessary or not.
Comment 70•11 years ago
|
||
Marco, can you take a look? Thanks.
Flags: needinfo?(amarchesini) → needinfo?(mchen)
Assignee | ||
Comment 71•11 years ago
|
||
(In reply to Star Cheng [:scheng] from comment #69)
> There is another strange point - there are 2 'ringer' audio channel are
> registered. Please see below. We should only need either.
>
> https://github.com/mozilla-b2g/gaia/blob/master/apps/system/js/dialer_agent.
> js#L46
> http://dxr.mozilla.org/mozilla-central/source/dom/system/gonk/AudioManager.
> cpp#539
>
> I try to disable the AudioManager part, and it works normally. I will
> investigate it and check weather the AudioManager part is necessary or not.
Thanks !
I'll check those other points.
Assignee | ||
Comment 72•11 years ago
|
||
(In reply to Star Cheng [:scheng] from comment #67)
> I found there is another telephony audio channel is registered before
> SetPhoneState aState as 2 (IN_Call mode). And add some log to trace it. It
> should be registered in keypad.js. Please see below log:
> (telephony audio channel type should be registered in
> AudioManager::setPhoneSteate())
I'm not able to find any evidence of two AudioContext('telephony') being created by TonePlayer.
Assignee | ||
Comment 73•11 years ago
|
||
> 05-14 14:27:00.140 5875 5875 I Gecko : AudioManager::SetPhoneState(-1 => 2)
> 05-14 14:27:02.820 5875 5875 I Gecko : AudioManager::SetPhoneState(2 => 2)
> 05-14 14:27:06.460 5875 5875 I Gecko : AudioManager::SetPhoneState(2 => 0)
I only see one new IN_CALL state :(
Flags: needinfo?(scheng)
Assignee | ||
Comment 74•11 years ago
|
||
This issue also reproduces when using the fake libril in JS of bug 989926.
Assignee | ||
Comment 75•11 years ago
|
||
Some fun with mulet+libril:
Starting Gaia:
> AudioChannelService::UnregisterAudioChannelAgent(0)
> AudioChannelService::RegisterType: 0
Then starting dialer :
> AudioChannelService::UnregisterAudioChannelAgent(0)
> AudioChannelService::RegisterType: 0
Placing a call :
> AudioChannelService::UnregisterAudioChannelAgent(4)
> AudioChannelService::RegisterType: 4
Hanging up:
> AudioChannelService::UnregisterAudioChannelAgent(0)
> AudioChannelService::RegisterType: 0
> AudioChannelService::UnregisterAudioChannelAgent(0)
> AudioChannelService::RegisterType: 0
> AudioChannelService::UnregisterAudioChannelAgent(0)
> AudioChannelService::RegisterType: 0
> AudioChannelService::UnregisterAudioChannelAgent(0)
> AudioChannelService::RegisterType: 0
More fun is that since it's a Mulet, I can open a tab. So I'm opening a second tab on |about:| then closing the |shell.html| tab. At which point, log shows that we FINALLY call unregister against the telephony channel. Then loading |chrome://b2g/content/shell.html| in the tab that I used to open |about:|, channel is okay again.
Assignee | ||
Comment 76•11 years ago
|
||
On device:
I/Gecko ( 3139): AudioChannelService::RegisterAudioChannelAgent(0)
I/Gecko ( 3139): AudioChannelService::RegisterType: 0
E/GeckoConsole( 3139): Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:49 in tp_trashAudio: TonePlayer: trashAudio(): delete AudioContext(null)
E/GeckoConsole( 3139): Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:43 in tp_ensureAudio: TonePlayer: ensureAudio(): new AudioContext(normal)
I/Gecko ( 3439): AudioChannelService::RegisterAudioChannelAgent(0)
I/Gecko ( 3439): AudioChannelService::RegisterType: 0
I/Gecko ( 3139): AudioChannelService::RegisterType: 0
I/Gecko ( 3139): AudioChannelService::RegisterAudioChannelAgent(4)
I/Gecko ( 3139): AudioChannelService::RegisterType: 4
E/GeckoConsole( 3139): Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:49 in tp_trashAudio: TonePlayer: trashAudio(): delete AudioContext(normal)
E/GeckoConsole( 3139): Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:43 in tp_ensureAudio: TonePlayer: ensureAudio(): new AudioContext(telephony)
I/Gecko ( 3139): AudioChannelService::RegisterAudioChannelAgent(4)
I/Gecko ( 3139): AudioChannelService::RegisterType: 4
I/Gecko ( 3439): AudioChannelService::RegisterAudioChannelAgent(0)
I/Gecko ( 3439): AudioChannelService::RegisterType: 0
I/Gecko ( 3139): AudioChannelService::RegisterType: 0
I/Gecko ( 3139): AudioChannelService::UnregisterAudioChannelAgent(4)
I/Gecko ( 3139): AudioChannelService::UnregisterType: 4
I/Gecko ( 3139): AudioChannelService::RegisterAudioChannelAgent(0)
I/Gecko ( 3139): AudioChannelService::RegisterType: 0
E/GeckoConsole( 3139): Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:49 in tp_trashAudio: TonePlayer: trashAudio(): delete AudioContext(telephony)
E/GeckoConsole( 3139): Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:43 in tp_ensureAudio: TonePlayer: ensureAudio(): new AudioContext(normal)
I/Gecko ( 3139): AudioChannelService::RegisterAudioChannelAgent(0)
I/Gecko ( 3139): AudioChannelService::RegisterType: 0
E/GeckoConsole( 3139): Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:49 in tp_trashAudio: TonePlayer: trashAudio(): delete AudioContext(normal)
E/GeckoConsole( 3139): Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:49 in tp_trashAudio: TonePlayer: trashAudio(): delete AudioContext(null)
E/GeckoConsole( 3139): Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:43 in tp_ensureAudio: TonePlayer: ensureAudio(): new AudioContext(normal)
I/Gecko ( 3139): AudioChannelService::RegisterAudioChannelAgent(0)
I/Gecko ( 3139): AudioChannelService::RegisterType: 0
E/GeckoConsole( 3139): Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:49 in tp_trashAudio: TonePlayer: trashAudio(): delete AudioContext(null)
E/GeckoConsole( 3139): Content JS DEBUG at app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js:43 in tp_ensureAudio: TonePlayer: ensureAudio(): new AudioContext(normal)
So there is clearly TWO telephony channels created, but only one seems to be created by TonePlayer's code.
Assignee | ||
Comment 77•11 years ago
|
||
So, thanks to gdb:
- the first telephony channel registered is because of TonePlayer
- the second one is because of this backtrace:
gdb) bt
#0 mozilla::dom::AudioChannelService::RegisterAudioChannelAgent (this=0xae022e80, aAgent=0xaddd4300, aChannel=mozilla::dom::Telephony, aWithVideo=<optimized out>)
at ../../../gecko/dom/audiochannel/AudioChannelService.cpp:121
#1 0xb54a7dd6 in mozilla::dom::AudioChannelAgent::StartPlaying (this=0xaddd4300, _retval=0xbed893b4) at ../../../gecko/dom/audiochannel/AudioChannelAgent.cpp:127
#2 0xb547d1a4 in SetPhoneState (aState=<optimized out>, this=0xb25f0d30) at ../../../../gecko/dom/system/gonk/AudioManager.cpp:544
#3 mozilla::dom::gonk::AudioManager::SetPhoneState (this=0xb25f0d30, aState=<optimized out>) at ../../../../gecko/dom/system/gonk/AudioManager.cpp:504
#4 0xb4d85c1e in NS_InvokeByIndex (that=<optimized out>, methodIndex=<optimized out>, paramCount=<optimized out>, params=<optimized out>)
at ../../../../../../../gecko/xpcom/reflect/xptcall/src/md/unix/xptcinvoke_arm.cpp:164
#5 0xb5373546 in Invoke (this=0xbed894c0) at ../../../../gecko/js/xpconnect/src/XPCWrappedNative.cpp:2397
#6 Call (this=0xbed894c0) at ../../../../gecko/js/xpconnect/src/XPCWrappedNative.cpp:1738
#7 XPCWrappedNative::CallMethod (ccx=<optimized out>, mode=<optimized out>) at ../../../../gecko/js/xpconnect/src/XPCWrappedNative.cpp:1705
#8 0xb537615a in SetAttribute (ccx=...) at ../../../../gecko/js/xpconnect/src/xpcprivate.h:2081
#9 XPC_WN_GetterSetter (cx=0xb6b10840, argc=1, vp=0xbed89990) at ../../../../gecko/js/xpconnect/src/XPCWrappedNativeJSOps.cpp:1301
#10 0xb5d076ac in CallJSNative (args=..., native=0xb537603d <XPC_WN_GetterSetter(JSContext*, unsigned int, JS::Value*)>, cx=0xb6b10840) at ../../../gecko/js/src/jscntxtinlines.h:239
#11 js::Invoke (cx=0xb6b10840, args=..., construct=js::NO_CONSTRUCT) at ../../../gecko/js/src/vm/Interpreter.cpp:475
#12 0xb5d08072 in js::Invoke (cx=0xb6b10840, thisv=<optimized out>, fval=..., argc=1, argv=0xbed89d60, rval=...) at ../../../gecko/js/src/vm/Interpreter.cpp:531
#13 0xb5d0814c in js::InvokeGetterOrSetter (cx=<optimized out>, obj=0xacf4b180, fval=..., argc=1, argv=0xbed89d60, rval=...) at ../../../gecko/js/src/vm/Interpreter.cpp:603
#14 0xb5c9d9fe in set (vp=..., strict=true, receiver=<optimized out>, obj=..., cx=0xb6b10840, this=0xaf658088) at ../../../gecko/js/src/vm/Shape-inl.h:95
#15 js::NativeSet<(js::ExecutionMode)0> (cxArg=<optimized out>, obj=..., receiver=<optimized out>, shape=..., strict=true, vp=...) at ../../../gecko/js/src/jsobj.cpp:4365
#16 0xb5ca08e8 in js::baseops::SetPropertyHelper<(js::ExecutionMode)0> (cxArg=0xb6b10840, obj=..., receiver=..., id=..., qualified=js::baseops::Qualified, vp=..., strict=true)
at ../../../gecko/js/src/jsobj.cpp:5062
#17 0xb5d0281c in SetPropertyOperation (rval=<optimized out>, lval=<optimized out>, pc=<optimized out>, script=..., cx=<optimized out>) at ../../../gecko/js/src/vm/Interpreter.cpp:335
#18 Interpret (cx=<optimized out>, state=...) at ../../../gecko/js/src/vm/Interpreter.cpp:2456
#19 0xb5d07494 in js::RunScript (cx=0xb6b10840, state=...) at ../../../gecko/js/src/vm/Interpreter.cpp:422
#20 0xb5d0763a in RunScript (state=..., cx=0xb6b10840) at ../../../gecko/js/src/vm/Interpreter.cpp:389
#21 js::Invoke (cx=0xb6b10840, args=..., construct=js::NO_CONSTRUCT) at ../../../gecko/js/src/vm/Interpreter.cpp:494
#22 0xb5d08072 in js::Invoke (cx=0xb6b10840, thisv=<optimized out>, fval=..., argc=3, argv=0xbed8a4b0, rval=...) at ../../../gecko/js/src/vm/Interpreter.cpp:531
#23 0xb5c59e2c in JS_CallFunctionValue (cx=0xb6b10840, obj=<optimized out>, fval=<optimized out>, args=<optimized out>, rval=...) at ../../../gecko/js/src/jsapi.cpp:5194
#24 0xb53705b6 in nsXPCWrappedJSClass::CallMethod (this=0xade50ca0, wrapper=<optimized out>, methodIndex=<optimized out>, info_=0xb2f6fdb8, nativeParams=0xbed8a550)
at ../../../../gecko/js/xpconnect/src/XPCWrappedJSClass.cpp:1272
#25 0xb536e338 in CallMethod (params=<optimized out>, info=0xb2f6fdb8, methodIndex=25, this=0xadb4b0c0) at ../../../../gecko/js/xpconnect/src/XPCWrappedJS.cpp:517
#26 nsXPCWrappedJS::CallMethod (this=0xadb4b0c0, methodIndex=<optimized out>, info=0xb2f6fdb8, params=<optimized out>) at ../../../../gecko/js/xpconnect/src/XPCWrappedJS.cpp:507
#27 0xb4d864a6 in PrepareAndDispatch (self=0xaddfacf0, methodIndex=<optimized out>, args=<optimized out>) at ../../../../../../../gecko/xpcom/reflect/xptcall/src/md/unix/xptcstubs_arm.cpp:93
#28 0xb4d85c68 in SharedStub () from /home/alex/codaz/Mozilla/b2g/devices/Flame/B2G/objdir-gecko/dist/bin/libxul.so
#29 0xb4d85c1e in NS_InvokeByIndex (that=<optimized out>, methodIndex=<optimized out>, paramCount=<optimized out>, params=<optimized out>)
at ../../../../../../../gecko/xpcom/reflect/xptcall/src/md/unix/xptcinvoke_arm.cpp:164
#30 0xb5373546 in Invoke (this=0xbed8a6f0) at ../../../../gecko/js/xpconnect/src/XPCWrappedNative.cpp:2397
#31 Call (this=0xbed8a6f0) at ../../../../gecko/js/xpconnect/src/XPCWrappedNative.cpp:1738
#32 XPCWrappedNative::CallMethod (ccx=<optimized out>, mode=<optimized out>) at ../../../../gecko/js/xpconnect/src/XPCWrappedNative.cpp:1705
#33 0xb5375cca in XPC_WN_CallMethod (cx=0xb6b10840, argc=2, vp=0xbed8a8b0) at ../../../../gecko/js/xpconnect/src/XPCWrappedNativeJSOps.cpp:1273
#34 0xb3dcc6c0 in ?? ()
#35 0xb3dcc6c0 in ?? ()
Comment 78•11 years ago
|
||
(In reply to Alexandre LISSY :gerard-majax from comment #77)
> So, thanks to gdb:
> - the first telephony channel registered is because of TonePlayer
> - the second one is because of this backtrace:
Have you tried invoking 'call DumpJSStack()' to see what JS methods are present on the stack when you hit that point? If you're testing this on a device you have to redirect the main process' stdout to see the output of that command.
Assignee | ||
Comment 79•11 years ago
|
||
(In reply to Gabriele Svelto [:gsvelto] from comment #78)
> (In reply to Alexandre LISSY :gerard-majax from comment #77)
> > So, thanks to gdb:
> > - the first telephony channel registered is because of TonePlayer
> > - the second one is because of this backtrace:
>
> Have you tried invoking 'call DumpJSStack()' to see what JS methods are
> present on the stack when you hit that point? If you're testing this on a
> device you have to redirect the main process' stdout to see the output of
> that command.
Nice trick :)
Assignee | ||
Comment 80•11 years ago
|
||
So I had a look at what happens regarding the registered channels. I found two calls to RegisterAudioChannelAgent, each one with a different agent, followed by a subsequent call to UnregisterAudioChannelAgent with only the second agent, when we hang up:
> I/Gecko ( 2216): AudioChannelService::RegisterAudioChannelAgent(aAgent=0xae121420) << Placing call
> I/Gecko ( 2216): AudioChannelService::RegisterAudioChannelAgent(aAgent=0xae0f9840) << Placing call
> I/Gecko ( 2216): AudioChannelService::UnregisterAudioChannelAgent(0xae0f9840) << Hanging call
This ordering is always constant.
With the help of gdb, I checked where did both agent came from:
- 0xae121420 is linked to the TonePlayer code in Gaia
- 0xae0f9840 is triggered by the gAudioManager lazy getter in TelephonyProvider in dom/telephony/gonk
So from this we clearly see that it is the audio agent from Gaia that is missing its unregister call and thus bugs us.
Thanks to DumpJSStack(), let's see what code triggers the registration of the gaia-side agent:
> 0 tp_ensureAudio() ["app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js":44]
> this = [object Object]
> 1 tp_setChannel(channel = "telephony") ["app://callscreen.gaiamobile.org/shared/js/dialer/tone_player.js":245]
> this = [object Object]
> 2 anonymous(e = [object Event]) ["app://callscreen.gaiamobile.org/shared/js/dialer/keypad.js":237]
> this = [object Object]
This is from the visibilitychange event handler.
Flags: needinfo?(scheng)
Flags: needinfo?(mchen)
Flags: needinfo?(etienne)
Updated•11 years ago
|
Whiteboard: [systemsfe][cert] → [systemsfe][cert][partner-blocker][sprd311363]
Assignee | ||
Comment 84•11 years ago
|
||
I know have an explanation.
The root of the issue is that we still have a 'telephony' channel registered. Debugging this, I came to the conclusion that:
(1) this is the channel created by TonePlayer() when creating an AudioContext('telephony')
(2) while we null the property holding the AudioContext, the effective release of the AudioContext happens when the window is closed
(3) when we trashAudio() we do not touch the mozAudioChannelType
(4) setChannel() in TonePlayer will always perform a trash/ensure step
Because of (4) and (2), we end up with a couple of AudioContext created that will be held until the window is closed, or ressources are collected. This explains (1).
I have a patch that fixes the issue in a more proper way than the first proposal:
- make setChannel() NOT call trashAudio() to avoid recreating unnecessary AudioContext(). This helps for (2)
- make setChannel() change the mozAudioChannelType to the new channel. This helps for ensuring we do not retain unnecessary telephony channel
- make trashAudio() force mozAudioChannelType to be null, for the same reason.
With those changes applied, I'm not able to reproduce anymore.
Comment 85•11 years ago
|
||
(In reply to Alexandre LISSY :gerard-majax from comment #84)
> (2) while we null the property holding the AudioContext, the effective
> release of the AudioContext happens when the window is closed
Yuck, is this because the AudioContext is wiped out only when the GC run? Or is it tied to the window's lifetime?
> With those changes applied, I'm not able to reproduce anymore.
+1000
Assignee | ||
Comment 86•11 years ago
|
||
Comment on attachment 8419456 [details] [review]
Link to Github https://github.com/mozilla-b2g/gaia/pull/19070
Updated PR with a much better fix.
Attachment #8419456 -
Flags: review+
Comment 87•11 years ago
|
||
(In reply to Alexandre LISSY :gerard-majax from comment #86)
> Updated PR with a much better fix.
I've left a couple of comments on GitHub, except for fixing up the unit-tests this LGTM.
Assignee | ||
Comment 88•11 years ago
|
||
So far I have unit tests, but writing device gaia ui test is way too risky for now. Bug 1011000 has been filed to make reliable tests when SoundManager refactoring is landed: it's much more stable than using events.
Assignee | ||
Comment 89•11 years ago
|
||
Comment on attachment 8419456 [details] [review]
Link to Github https://github.com/mozilla-b2g/gaia/pull/19070
Etienne, please find attached a PR that fixes the issue.
Attachment #8419456 -
Flags: review?(etienne)
Comment 90•11 years ago
|
||
Comment on attachment 8419456 [details] [review]
Link to Github https://github.com/mozilla-b2g/gaia/pull/19070
Comments on github but kudos on the tests!
Attachment #8419456 -
Flags: review?(etienne) → review+
Comment 91•11 years ago
|
||
bug 984498 cause this issue.
Updated•11 years ago
|
Whiteboard: [systemsfe][cert][partner-blocker][sprd311363] → [systemsfe][cert][partner-blocker][sprd311363][sprd311363]
Assignee | ||
Comment 92•11 years ago
|
||
Thanks Etienne, comments addressed. New Travis at https://travis-ci.org/mozilla-b2g/gaia/builds/25312792.
Assignee | ||
Comment 93•11 years ago
|
||
Comment on attachment 8419456 [details] [review]
Link to Github https://github.com/mozilla-b2g/gaia/pull/19070
Anthony, do you mind to put your eyes on the changes ? That's the removal of the setChannel() call part :)
Attachment #8419456 -
Flags: review?(anthony)
Comment 94•11 years ago
|
||
It's OK in hamachi
Assignee | ||
Comment 95•11 years ago
|
||
(In reply to Dafeng Xu from comment #94)
> It's OK in hamachi
What is okay exactly ?
Flags: needinfo?(Dafeng.Xu)
Assignee | ||
Comment 96•11 years ago
|
||
Travis is green. https://travis-ci.org/mozilla-b2g/gaia/builds/25312792
Updated•11 years ago
|
Attachment #8419456 -
Flags: review?(anthony) → review+
Assignee | ||
Comment 97•11 years ago
|
||
Status: ASSIGNED → RESOLVED
Closed: 11 years ago
Resolution: --- → FIXED
Comment 98•11 years ago
|
||
Looks like this is going to need branch-specific patches for uplift. Don't forget to request approval-gaia-v1.3 on the 1.3 patch :)
status-b2g-v1.3:
--- → affected
status-b2g-v1.4:
--- → affected
status-b2g-v2.0:
--- → fixed
Flags: needinfo?(lissyx+mozillians)
Keywords: branch-patch-needed
Comment 99•11 years ago
|
||
(In reply to Alexandre LISSY :gerard-majax from comment #95)
> (In reply to Dafeng Xu from comment #94)
> > It's OK in hamachi
>
> What is okay exactly ?
The attachment 8419456 [details] [review] link to Github https://github.com/mozilla-b2g/gaia/pull/19070.
I just test it in hamachi, It's OK
Flags: needinfo?(Dafeng.Xu)
Comment 100•11 years ago
|
||
We need land it to 1.3t
Comment 101•11 years ago
|
||
(In reply to James Zhang from comment #100)
> We need land it to 1.3t
Flags: needinfo?(fabrice)
Comment 102•11 years ago
|
||
1.3t: https://github.com/mozilla-b2g/gaia/commit/917174ee3812a43758bf43f7ba5f9416dcdb2ca8
Note: this still needs to go through the normal approval/uplift process for 1.3 as well.
Flags: needinfo?(fabrice)
Assignee | ||
Comment 103•11 years ago
|
||
(In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #98)
> Looks like this is going to need branch-specific patches for uplift. Don't
> forget to request approval-gaia-v1.3 on the 1.3 patch :)
I'm sorry, but I don't see the callscreen app on v1.3. Hence, I don't think we need to uplift this on 1.3.
Flags: needinfo?(lissyx+mozillians)
Assignee | ||
Comment 104•11 years ago
|
||
(In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #98)
> Looks like this is going to need branch-specific patches for uplift. Don't
> forget to request approval-gaia-v1.3 on the 1.3 patch :)
Can QA cross check whether this issue reproduces on v1.3 ?
Keywords: qawanted
Comment 105•11 years ago
|
||
(In reply to Dafeng Xu from comment #94)
> It's OK in hamachi
We have verified this patch on tarako, not hamachi.
Comment 106•11 years ago
|
||
v1.3t is permared because of the uplift: https://travis-ci.org/mozilla-b2g/gaia/jobs/25441555
Could someone please fix the "mock is undefined" error? Probably only needs to require the correct file.
Flags: needinfo?(lissyx+mozillians)
Assignee | ||
Comment 107•11 years ago
|
||
That should fix the test failure reported by julien.
Attachment #8424770 -
Flags: review?(etienne)
Flags: needinfo?(lissyx+mozillians)
Assignee | ||
Comment 108•11 years ago
|
||
Travis is green: https://travis-ci.org/mozilla-b2g/gaia/builds/25508424
Updated•11 years ago
|
Attachment #8424770 -
Flags: review?(etienne) → review+
Assignee | ||
Comment 109•11 years ago
|
||
Comment 110•11 years ago
|
||
(In reply to Alexandre LISSY :gerard-majax from comment #103)
> I'm sorry, but I don't see the callscreen app on v1.3. Hence, I don't think
> we need to uplift this on 1.3.
What about v1.4? Also, a 1.3+ blocking status on a bug that doesn't affect 1.3 doesn't make a whole lot of sense.
Flags: needinfo?(lissyx+mozillians)
Comment 111•11 years ago
|
||
This issue does not reproduce on 1.3 Buri.
1.3 Environmental Variables:
Device: Buri 1.3 MOZ
BuildID: 20140521062818
Gaia: 0ce948e378cab7ed3db20231281dd7ca2eb99779
Gecko: fce835f24818
Version: 28.0
Firmware Version: v1.2-device.cfg
Volume change does not get stuck on call volume.
Keywords: qawanted
Updated•11 years ago
|
Comment 112•11 years ago
|
||
Adding qawanted to check 1.4 as well.
blocking-b2g: 1.3+ → 1.3T+
Keywords: qawanted
Updated•11 years ago
|
Whiteboard: [systemsfe][cert][partner-blocker][sprd311363][sprd311363] → [systemsfe][partner-blocker][sprd311363][sprd311363]
Comment 113•11 years ago
|
||
This issue does not occur on today's Buri 1.4 build.
1.4 Environmental Variables:
Device: Buri 1.4 MOZ
BuildID: 20140521070720
Gaia: 5cf90f2bc058c8a8f9353ee7381f546791d27405
Gecko: 8dae6f96a13a
Version: 30.0
Firmware Version: v1.2-device.cfg
Volume change does not get stuck on call volume.
Keywords: qawanted
Comment 114•11 years ago
|
||
Clearing branch-patch-needed since this only needs to land on 1.3T & 2.0.
Flags: needinfo?(lissyx+mozillians)
Keywords: branch-patch-needed
Comment 115•10 years ago
|
||
You need to log in
before you can comment on or make changes to this bug.
Description
•