Closed Bug 1070066 Opened 10 years ago Closed 10 years ago

[Dialer] The call screen does not display call info and shows a black background after repeatedly placing calls

Categories

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

ARM
Gonk (Firefox OS)
defect
Not set
normal

Tracking

(blocking-b2g:2.1+, b2g-v2.0 unaffected, b2g-v2.1 affected, b2g-v2.2 affected)

RESOLVED DUPLICATE of bug 1068109
blocking-b2g 2.1+
Tracking Status
b2g-v2.0 --- unaffected
b2g-v2.1 --- affected
b2g-v2.2 --- affected

People

(Reporter: smiko, Assigned: thills)

References

()

Details

(Keywords: regression, Whiteboard: [2.1-flame-test-run-2])

Attachments

(2 files)

Attached file NoInfo.txt
Description: After repeatedly calling and hanging up, the call screen will display a black background and the call information will not display. Repro Steps: 1: Update a Flame to 20140919000204 2: Open Dialer and use keypad to type in a valid 10 digit number 3: Place the call and immediately hang up. 4: Press the dial button on the keypad screen to redial the number. 5: Immediately hang up 6: Repeat steps 4 and 5 up to 10 times Actual: The call screen displays a black background. The number calling does not appear. Expected: The home wallpaper is shown as well as the number dialed. Flame 2.1(319mb) Environmental Variables: Device: Flame 2.1 (319mb) Build ID: 20140919000204 Gaia: 2a612867039a7cfb3af6e692bfae4482b06705e9 Gecko: 004bc0d262e5 Version: 34.0a2 (Master) Firmware Version: v123 User Agent: Mozilla/5.0 (Mobile; rv:34.0) Gecko/34.0 Firefox/34.0 Notes: 1: Once this issue occurs, the black screen will be displayed when calling until rebooting the phone. 2: Calls made with the black screen displayed do not appear in the call log. 3: May be related to Bug 819467 Repro frequency: 100% See attached: logcat Video clip: http://youtu.be/RqE-LNfUOj4
This issue DOES occur on Flame 2.2(319mb), Open C 2.2, Flame 2.1(512mb), Flame 2.1 KK base(319mb), and Open C 2.1 Actual Result: The call screen displays a black background. The number calling does not appear. Flame 2.2 (319mb) Environmental Variables: Device: Flame 2.2 Build ID: 20140919040205 Gaia: bc2da39ccd2b82b67773f10c8da8fc8eedc483ab Gecko: c8e325eee9e1 Version: 35.0a1 Firmware Version: v123 User Agent: Mozilla/5.0 (Mobile; rv:35.0) Gecko/35.0 Firefox/35.0 Open C 2.2 Environmental Variables: Device: Open_C 2.2 Build ID: 20140919040205 Gaia: bc2da39ccd2b82b67773f10c8da8fc8eedc483ab Gecko: c8e325eee9e1 Version: 35.0a1 Firmware: P821A10v1.0.0B06_LOG_DL User Agent: Mozilla/5.0 (Mobile; rv:35.0) Gecko/35.0 Firefox/35.0 Flame 2.1 (512 mb) Environmental Variables: Device: Flame 2.1 BuildID: 20140919000204 Gaia: 2a612867039a7cfb3af6e692bfae4482b06705e9 Gecko: 004bc0d262e5 Version: 34.0a2 (2.1) Firmware Version: v123 User Agent: Mozilla/5.0 (Mobile; rv:34.0) Gecko/34.0 Firefox/34.0 Flame 2.1 KitKat Base (319mb) Environmental Variables: Device: Flame 2.1 (319mb) Build ID: 20140919063003 Gaia: f0f22bb46c881e02524b3991c2587ff8c0a9fc37 Gecko: ab2a88c05a4b Version: 34.0a2 Firmware Version: v180 User Agent: Mozilla/5.0 (Mobile; rv:34.0) Gecko/34.0 Firefox/34.0 Open C 2.1 Environmental Variables: Device: Open_C 2.1 Build ID: 20140919000204 Gaia: 2a612867039a7cfb3af6e692bfae4482b06705e9 Gecko: 004bc0d262e5 Version: 34.0a2 (Master) Firmware Version: P821A10V1.0.0B06_LOG_DL User Agent: Mozilla/5.0 (Mobile; rv:34.0) Gecko/34.0 Firefox/34.0 This issue does NOT occur on Flame 2.0(319mb) JB base, Flame 2.0(319mb) KK base, or Open C 2.0 Actual Result: The screen displays the home wallpaper and the number calling Flame 2.0 (319mb) Environmental Variables: Device: Flame 2.0 (319mb) Build ID: 20140919000204 Gaia: 31434a3949556171f3565ca47ac2b44e810e95e6 Gecko: a10034c1964f Version: 32.0 (2.0) Firmware Version: v123 User Agent: Mozilla/5.0 (Mobile; rv:32.0) Gecko/32.0 Firefox/32.0 Flame 2.0 KitKat Base (319mb) Environmental Variables: Device: Flame 2.0 Build ID: 20140919063017 Gaia: 31434a3949556171f3565ca47ac2b44e810e95e6 Gecko: fb1589259e4f Version: 32.0 (2.0) Firmware Version: v180 User Agent: Mozilla/5.0 (Mobile; rv:32.0) Gecko/32.0 Firefox/32.0 Open_C 2.0 Enviromental Variables: Device: Open_C 2.0 Build ID: 20140919000204 Gaia: 31434a3949556171f3565ca47ac2b44e810e95e6 Gecko: a10034c1964f Version: 32.0 (2.0) Firmware: P821A10v1.0.0B06_LOG_DL User Agent: Mozilla/5.0 (Mobile; rv:32.0) Gecko/32.0 Firefox/32.0
QA Whiteboard: [QAnalyst-Triage?]
Flags: needinfo?(dharris)
Keywords: regression
Summary: [Dialer] The call screen does not display call info and shows a black background after repeatedly placing a calls → [Dialer] The call screen does not display call info and shows a black background after repeatedly placing calls
Whiteboard: [2.1-flame-test-run-2]
I think this could be related to the attention window changes. That's bug 927862. Bug 1068109 will probably fix this by re-introducing a 2s delay that we lost.
Please note that the Environmental Variables from comment 0 are for Flame 2.1 (319mb) and not master.
[Blocking Requested - why for this release]: Nominating this because it is a regression, and the UI can become unusable
blocking-b2g: --- → 2.1?
QA Whiteboard: [QAnalyst-Triage?]
Flags: needinfo?(dharris)
QA Contact: smiko
triage: regression
blocking-b2g: 2.1? → 2.1+
Assignee: nobody → thills
Initial Regression Window: mozilla-central-flame Last Working Device: Flame Master BuildID: 20140830094116 Gaia: c05ee27dd1f39e0f1cceb8bc7706e20f297cd9df Gecko: 82e1c0a8c589 Version: 34.0a1 First Broken Device: Flame Master BuildID: 20140830195315 Gaia: 2be78d83a760fa3b9638fe51c266b442d14597f1 Gecko: 1db35d2c9a2f Version: 34.0a1 1st Broken Gaia/Last Working Gecko- Issue does NOT repro Gaia: 2be78d83a760fa3b9638fe51c266b442d14597f1 Gecko: 82e1c0a8c589 Last working Gaia/First Broken Gecko- Issue DOES repro = gecko issue Gaia: c05ee27dd1f39e0f1cceb8bc7706e20f297cd9df Gecko: 1db35d2c9a2f 1st Push Log http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=82e1c0a8c589&tochange=1db35d2c9a2f ---------------------------------------------------------------------- B2G Inbound Last Working BuildID: 20140829133157 Gaia: 3a95ab1c33084d110351a39eb86d49a18bcf39f3 Gecko: 6dc0a998af58 First Broken BuildID: 20140829140157 Gaia: 3a95ab1c33084d110351a39eb86d49a18bcf39f3 Gecko: 6b1690ad2cf5 B2G Inbound Push Log hg.mozilla.org/integration/b2g-inbound/pushloghtml?fromchange=6dc0a998af58&tochange=6b1690ad2cf5
QA Whiteboard: [QAnalyst-Triage?]
Flags: needinfo?(jmitchell)
Kyle - the pushlog has only 2 patches, both yours - could you investigate? http://hg.mozilla.org/integration/b2g-inbound/pushloghtml?fromchange=6dc0a998af58&tochange=6b1690ad2cf5
QA Whiteboard: [QAnalyst-Triage?] → [QAnalyst-Triage+]
Flags: needinfo?(jmitchell) → needinfo?(kyle)
QA Contact: smiko
Not reproducable on 2.2 built yesterday, and STR was done before a bunch of settings patches landed to both 2.1 and 2.2. Requesting qa reverification on current build.
Flags: needinfo?(kyle)
Keywords: qawanted
Actually, half the STR works (tried again a couple of times after posting last comment). I don't get a black background, but call info does still disappear. Closing and reopening dialer app still shows no call info.
Ok. The patches that I mentioned earlier added some error messages, I'm now seeing W/GeckoConsole( 205): [JavaScript Error: "TypeError: this._settingsManager._window is null" {file: "jar:file:///system/b2g/omni.ja!/components/SettingsManager.js" line: 118}] W/GeckoConsole( 205): [JavaScript Error: "NS_ERROR_UNEXPECTED: " {file: "app://callscreen.gaiamobile.org/shared/js/dialer/voicemail.js" line: 18}] in the logs. I bet this is a settings race due to the new transaction system. Will take a look.
Keywords: qawanted
From build I just made with more debugging messages: W/GeckoConsole( 206): [JavaScript Error: "SettingsManager window died, cannot run settings transaction." {file: "jar:file:///system/b2g/omni.ja!/components/SettingsManager.js" line: 116}] W/GeckoConsole( 206): [JavaScript Error: "SettingsMessage: Settings:CreateLock" {file: "jar:file:///system/b2g/omni.ja!/components/SettingsManager.js" line: 117}] W/GeckoConsole( 206): [JavaScript Error: "SettingsData: {"lockID":"{df433a21-d619-4db5-85da-bd902a793580}","isServiceLock":false}" {file: "jar:file:///system/b2g/omni.ja!/components/SettingsManager.js" line: 118}] W/GeckoConsole( 206): [JavaScript Error: "NS_ERROR_UNEXPECTED: Component returned failure code: 0x8000ffff (NS_ERROR_UNEXPECTED) [nsIDOMRequestService.createRequest]" {file: "resource://gre/modules/DOMRequestHelper.jsm" line: 279}] W/GeckoConsole( 206): [JavaScript Error: "NS_ERROR_UNEXPECTED: " {file: "app://callscreen.gaiamobile.org/shared/js/dialer/voicemail.js" line: 18}] It looks like at some point, we're trying to check voicemail but failing because we no longer have an inner window. Trying to trace why that happens now.
Talked to :thills on IRC, bug 1068109 should fix this, though it's still odd that settings wouldn't be able to reestablish a window after an app shut down like this. I'll take a look at that elsewhere.
I'm now seeing an IDB error whenever I try the repro steps. Even just once. I/GeckoConsole( 205): Content JS LOG: Error handling bluetooth request I/GeckoConsole( 205): at BluetoothHelper/_handleRequest/request.onerror (app://callscreen.gaiamobile.org/shared/js/bluetooth_helper.js:39:6) W/GeckoConsole( 205): [JavaScript Error: "NS_ERROR_FAILURE: " {file: "chrome://global/content/BrowserElementChildPreload.js" line: 998}] W/Usage ( 3403): Content JS WARN: SimManager is not ready, waiting for initialized custom event W/Usage ( 3403): at _requestService (app://costcontrol.gaiamobile.org/js/sim_manager.js:86:0) I/Gecko ( 3428): ###################################### forms.js loaded I/Gecko ( 3428): ############################### browserElementPanning.js loaded I/Gecko ( 3428): ######################## BrowserElementChildPreload.js loaded W/Usage ( 3403): Content JS WARN: The setting ril.data.defaultServiceId does not exists, using default Slot (0) W/Usage ( 3403): at _onsuccesSlotId (app://costcontrol.gaiamobile.org/js/sim_manager.js:52:0) W/Usage ( 3403): [JavaScript Error: "IndexedDB UnknownErr: IDBDatabase.cpp:779"] :bent, that last line is worrisome. It looks like IDB is dying in its AbortTransactions function. Any ideas?
Flags: needinfo?(bent.mozilla)
I'd ignore it for now... Warnings in the new IDB backend are a little too vocal. I will scale them back soon.
Flags: needinfo?(bent.mozilla)
I agree with :bent, still working on instrumenting this, but something weird is happening in callscreen (which runs as part of the parent process, which is where I'm seeing the error happen, so it's definitely callscreen, NOT dialer) trying to run Voicemail.check during the beginning of a call. Working on reproing it and getting a decent logcat now.
Here's a logcat of the voicemail failure, though it's kinda spammy because I had SettingsRequestManager debugging on to see if it was settings, plus some debug messages in to show where voicemail was being checked, and when that check returned. So, as you can see, the voicemail failure happens in the process with pid 205. That's the system process, where the callscreen app is launched. We also request voicemail for one of the callscreen runs at the beginning of the log I pasted, but it never gets the return it expects. Since voicemail is only checked in the updateCallNumber function of callscreen's handled_call.js, it seems like there's something that's taking a REALLY long time to get to that function. During execution of the STR, it seems like each successive loop of dial/hangup is a little slower than the last. So I'm guessing something is building up here, maybe a leak or something, but I'm not quite sure what.
We check if a call is to a voicemail when we receive a call (in the callscreen app, so system process) and when a call has ended (in the dialer app, own process) to store this information in the call log. The check first checks navigator.mozVoicemail (aka SIM card info) and then does a mozSettings query. What I'm seeing in this log is that the query from 1440 (Dialer PID) fails in the 205 process.
On a flame with a debug build, I'm doing some dumb memory watching (basically running b2g-ps between every call/hangup loop) and it looks like memory is going up 300-500k per call in the SYSTEM process (meaning something's up with callscreen), and isn't being released when killing the dialer. Someone with more knowledge on how to profile memory in gaia apps might want to try the STR in Comment 0 and see if they can get more info?
Ran get_about_memory real quick, looks like we're keeping a ton of cached callscreen objects around in the system process, hence the memory growth. ├──19.95 MB (24.87%) -- window-objects │ ├──19.42 MB (24.20%) -- top(app://system.gaiamobile.org/index.html, id=3) │ │ ├──12.28 MB (15.31%) -- cached │ │ │ ├───0.89 MB (01.11%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268242884) │ │ │ ├───0.89 MB (01.11%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268286937) │ │ │ ├───0.89 MB (01.11%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268290378) │ │ │ ├───0.89 MB (01.11%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268301149) │ │ │ ├───0.89 MB (01.11%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412269759847) │ │ │ ├───0.89 MB (01.11%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268257010) │ │ │ ├───0.89 MB (01.11%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268231577) │ │ │ ├───0.88 MB (01.10%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268235263) │ │ │ ├───0.87 MB (01.09%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268246112) │ │ │ ├───0.87 MB (01.09%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412269763650) │ │ │ ├───0.87 MB (01.09%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268293766) │ │ │ ├───0.85 MB (01.05%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268260071) │ │ │ ├───0.85 MB (01.05%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412269770146) │ │ │ └───0.84 MB (01.05%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268252785) Dunno if that's bad or not?
Um. Ok. Closed dialer. No apps open. ├──20.13 MB (24.78%) -- window-objects │ ├──19.60 MB (24.12%) -- top(app://system.gaiamobile.org/index.html, id=3) │ │ ├──12.26 MB (15.09%) -- cached │ │ │ ├───0.89 MB (01.10%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268257010) │ │ │ ├───0.89 MB (01.10%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268242884) │ │ │ ├───0.89 MB (01.10%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268286937) │ │ │ ├───0.89 MB (01.10%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268290378) │ │ │ ├───0.89 MB (01.10%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268301149) │ │ │ ├───0.89 MB (01.10%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412269759847) │ │ │ ├───0.89 MB (01.10%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268231577) │ │ │ ├───0.88 MB (01.08%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268235263) │ │ │ ├───0.87 MB (01.07%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268246112) │ │ │ ├───0.87 MB (01.07%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412269763650) │ │ │ ├───0.87 MB (01.07%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268293766) │ │ │ ├───0.84 MB (01.04%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268260071) │ │ │ ├───0.84 MB (01.04%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412269770146) │ │ │ └───0.84 MB (01.03%) ++ window(app://callscreen.gaiamobile.org/index.html#&timestamp=1412268252785) │ │ ├───5.59 MB (06.89%) -- active │ │ │ ├──4.85 MB (05.97%) -- window(app://system.gaiamobile.org/index.html) │ │ │ │ ├──2.33 MB (02.87%) -- js-compartment(app://system.gaiamobile.org/index.html) │ │ │ │ │ ├──1.53 MB (01.89%) ++ classes │ │ │ │ │ └──0.80 MB (00.98%) ++ (5 tiny) │ │ │ │ ├──1.18 MB (01.45%) ++ layout │ │ │ │ ├──0.85 MB (01.05%) ── style-sheets │ │ │ │ └──0.49 MB (00.60%) ++ (2 tiny) │ │ │ └──0.74 MB (00.91%) ++ window(app://callscreen.gaiamobile.org/index.html) │ │ └───1.74 MB (02.15%) -- js-zone(0xaf24fc00) │ │ ├──0.92 MB (01.13%) ++ (5 tiny) │ │ └──0.82 MB (01.01%) ── unused-gc-things Why is there still an active callscreen window in the system process? It was my understanding callscreen only existed when up, wasn't actually ever backgrounded?
ni'ing khuey for memory log translation
Flags: needinfo?(khuey)
The cached bit means that Gecko thinks the window is in the bfcache. Do we remove the callscreen iframe entirely? or do we navigate it to about:blank or something?
Flags: needinfo?(khuey)
We call window.close() from within the callscreen app.
And what does the system app do with that?
It wouldn't shock me if the mozbrowser code doesn't handle that correctly.
Kyle, I can confirm the leaking of callscreen. It happens as soon as I place several calls. STR: 0. python tools/get_about_memory.py 1. Place multiple calls 2. python tools/get_about_memory.py Expected: Same amount of callscreen in window-objects section for 0 and 2. Actual: Memory report in 2 has much more callscreen window-objects than the one in 0.
Assignee: thills → drs+bugzilla
(In reply to Alexandre LISSY :gerard-majax from comment #27) > Kyle, I can confirm the leaking of callscreen. It happens as soon as I place > several calls. > > STR: > 0. python tools/get_about_memory.py > 1. Place multiple calls > 2. python tools/get_about_memory.py > > Expected: > Same amount of callscreen in window-objects section for 0 and 2. > > Actual: > Memory report in 2 has much more callscreen window-objects than the one in > 0. Yep, me too. Olli, are we expecting to bfcache mozbrowser frames on b2g? This is quite surprising to me.
Flags: needinfo?(bugs)
is it oop mozbrowser? Then I'd expect bfcache, or at least I don't recall anything which would have disabled bfcache in TabChild.
Flags: needinfo?(bugs)
Is it top level iframe/xul:browser (under the very top level xul/chrome thing - I assume we still have that)? Such docshell would have a bfcache too, as expect. IIRC b2g limits cache to 1 entry though.
I believe it's a subframe of the system app, so no. And it certainly appears that there's more than one entry.
QA: Can we test this bug with the patch from bug 1068109 applied? To see if it fixes the issue.
Keywords: qawanted
I seem to recall we had a BF cache issue earlier and we solved it by adding an empty unload handler. I think this was creating issues with System messages. I can't find this empty unload handler anymore in the code. I'll look into our git history to see if we were able to remove it.
The BF cache issue was bug 1030550 and we only landed this in 2.0. For 2.1 and later, we fixed the platform directly in bug 1035074.
Correction of comment 33: Sorry, I meant testing with the patch from bug 1076597.
I am not able to reproduce this bug anymore by following the STR in comment 0 when I apply attachment 8498652 [details] [diff] [review]. Let's mark bug 1076597 as a dependency and clear the QA work here. We should verify the fix once bug 1076597 is landed.
Depends on: 1076597
Keywords: qawanted
See Also: → 1078448
The original issue is now effectively fixed by bug 1068109, which just landed. Verifying that bug 1076597 fixes this is too complicated as it will require a backout of bug 1068109 first. On top of that, another related bug, bug 1074379 requires bug 1076597 and is not fixed by bug 1068109, so we'll get practical verification that bug 1076597 is effective there.
Status: NEW → RESOLVED
Closed: 10 years ago
No longer depends on: 1076597
Resolution: --- → DUPLICATE
See Also: → 1076597
Assignee: drs+bugzilla → thills
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: