993354 - [B2G] Large delay before the first getText promise is fulfilled

Status: RESOLVED DUPLICATE of bug 992346

(Firefox OS Graveyard :: Gaia::Keyboard, defect, P3)

Description

[Rudy Lu [:rudyl] (inactive after 2015/7/3)]

Attachment: getText_time.log

+++ This bug was initially created as a clone of Bug #992346 +++

When testing bug 992346 on Tarako, we found that it might be have some delay before the getText promise is fulfilled.
This bug is opened to track the same issue on master, with OOP enabled and tested on buri.

--
As the attached log shows, it would have 230 - 320 ms delay before the promise is fulfilled.
After that, it would take only 40ms or so for the promise to be fulfilled.

Comment 1

[Rudy Lu [:rudyl] (inactive after 2015/7/3)]

Comment on attachment 8403215 [details]
getText_time.log

>04-08 19:27:25.259: E/GeckoConsole(1454): Content JS LOG at app://system.gaiamobile.org/js/keyboard_manager.js:91 in km_debug: [Keyboard Manager] get focus event text
>04-08 19:27:25.259: E/GeckoConsole(1454): Content JS LOG at app://system.gaiamobile.org/js/keyboard_manager.js:91 in km_debug: [Keyboard Manager] set layout to display: type=text index=0
>04-08 19:27:25.259: E/GeckoConsole(1454): Content JS LOG at app://system.gaiamobile.org/js/keyboard_manager.js:91 in km_debug: [Keyboard Manager] this layout is running
>04-08 19:27:25.269: E/GeckoConsole(1454): Content JS LOG at app://system.gaiamobile.org/js/keyboard_manager.js:91 in km_debug: [Keyboard Manager] setLayoutFrameActive: app://keyboard.gaiamobile.org/manifest.webapp/index.html#en, active: true
>04-08 19:27:25.399: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:414 in initKeyboard/window.navigator.mozInputMethod.oninputcontextchange: inputcontextchange
>04-08 19:27:25.399: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:418 in initKeyboard/window.navigator.mozInputMethod.oninputcontextchange: showKeyboard from inputcontextchange
>04-08 19:27:25.409: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:1667 in showKeyboard: showKeyboard()
>04-08 19:27:25.729: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:1732 in gotText: gotText

This is the first time the getText gets fulfilled, it took about 320ms.

>04-08 19:27:25.729: E/GeckoConsole(1454): Content JS LOG at app://system.gaiamobile.org/js/keyboard_manager.js:91 in km_debug: [Keyboard Manager] resizeKeyboard: 230
>04-08 19:27:25.739: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:1710 in doShowKeyboard: doShowKeyboard()
>04-08 19:27:25.739: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/imes/latin/latin.js:848 in updateCapitalization: key updateCapitalization
>04-08 19:27:25.739: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/imes/latin/latin.js:872 in updateCapitalization: key updateCapitalization: cursor - 0
>04-08 19:27:25.749: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:756 in startTime: startBLOCKING (main) renderKeyboard 1396956445439
>04-08 19:27:25.759: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:760 in endTime: ~BLOCKING (main) renderKeyboard 76
>04-08 19:27:25.759: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:893 in updateTargetWindowHeight: updateTargetWindowHeight()
>04-08 19:27:26.169: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:756 in startTime: startBLOCKING (nextTick) renderKeyboard 1396956446096
>04-08 19:27:26.169: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:760 in endTime: ~BLOCKING (nextTick) renderKeyboard 27
>04-08 19:27:26.249: E/GeckoConsole(1454): Content JS LOG at app://system.gaiamobile.org/js/keyboard_manager.js:91 in km_debug: [Keyboard Manager] showKeyboard display transitionend
>04-08 19:27:26.269: E/GeckoConsole(1454): Content JS LOG at app://system.gaiamobile.org/js/keyboard_manager.js:91 in km_debug: [Keyboard Manager] updateHeight: 230
>04-08 19:28:27.419: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:414 in initKeyboard/window.navigator.mozInputMethod.oninputcontextchange: inputcontextchange
>04-08 19:28:27.509: E/GeckoConsole(1454): Content JS LOG at app://system.gaiamobile.org/js/keyboard_manager.js:91 in km_debug: [Keyboard Manager] get blur event
>04-08 19:28:27.989: E/GeckoConsole(1454): Content JS LOG at app://system.gaiamobile.org/js/keyboard_manager.js:91 in km_debug: [Keyboard Manager] hideKeyboard display transitionend
>04-08 19:28:27.989: E/GeckoConsole(1454): Content JS LOG at app://system.gaiamobile.org/js/keyboard_manager.js:91 in km_debug: [Keyboard Manager] setLayoutFrameActive: app://keyboard.gaiamobile.org/manifest.webapp/index.html#en, active: false
>04-08 19:28:28.209: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:893 in updateTargetWindowHeight: updateTargetWindowHeight()
>04-08 19:28:28.609: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:400 in visibilityHandler: visibilitychange
>04-08 19:28:30.209: E/GeckoConsole(1454): Content JS LOG at app://system.gaiamobile.org/js/keyboard_manager.js:91 in km_debug: [Keyboard Manager] get focus event text
>04-08 19:28:30.209: E/GeckoConsole(1454): Content JS LOG at app://system.gaiamobile.org/js/keyboard_manager.js:91 in km_debug: [Keyboard Manager] set layout to display: type=text index=0
>04-08 19:28:30.219: E/GeckoConsole(1454): Content JS LOG at app://system.gaiamobile.org/js/keyboard_manager.js:91 in km_debug: [Keyboard Manager] this layout is running
>04-08 19:28:30.219: E/GeckoConsole(1454): Content JS LOG at app://system.gaiamobile.org/js/keyboard_manager.js:91 in km_debug: [Keyboard Manager] setLayoutFrameActive: app://keyboard.gaiamobile.org/manifest.webapp/index.html#en, active: true
>04-08 19:28:30.309: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:400 in visibilityHandler: visibilitychange
>04-08 19:28:30.319: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:414 in initKeyboard/window.navigator.mozInputMethod.oninputcontextchange: inputcontextchange
>04-08 19:28:30.319: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:418 in initKeyboard/window.navigator.mozInputMethod.oninputcontextchange: showKeyboard from inputcontextchange
>04-08 19:28:30.319: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:1667 in showKeyboard: showKeyboard()
>04-08 19:28:30.359: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:1732 in gotText: gotText

and here is the second time, about 40ms only.

>04-08 19:28:30.369: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:1710 in doShowKeyboard: doShowKeyboard()
>04-08 19:28:30.379: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/imes/latin/latin.js:848 in updateCapitalization: key updateCapitalization
>04-08 19:28:30.379: E/GeckoConsole(1454): Content JS LOG at app://system.gaiamobile.org/js/keyboard_manager.js:91 in km_debug: [Keyboard Manager] resizeKeyboard: 230
>04-08 19:28:30.379: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/imes/latin/latin.js:872 in updateCapitalization: key updateCapitalization: cursor - 0
>04-08 19:28:30.389: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:756 in startTime: startBLOCKING (main) renderKeyboard 1396956510335
>04-08 19:28:30.389: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:760 in endTime: ~BLOCKING (main) renderKeyboard 11
>04-08 19:28:30.399: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:893 in updateTargetWindowHeight: updateTargetWindowHeight()
>04-08 19:28:30.509: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:756 in startTime: startBLOCKING (nextTick) renderKeyboard 1396956510407
>04-08 19:28:30.509: E/GeckoConsole(1566): Content JS LOG at app://keyboard.gaiamobile.org/js/keyboard.js:760 in endTime: ~BLOCKING (nextTick) renderKeyboard 23
>04-08 19:28:30.849: E/GeckoConsole(1454): Content JS LOG at app://system.gaiamobile.org/js/keyboard_manager.js:91 in km_debug: [Keyboard Manager] showKeyboard display transitionend
>04-08 19:28:30.849: E/GeckoConsole(1454): Content JS LOG at app://system.gaiamobile.org/js/keyboard_manager.js:91 in km_debug: [Keyboard Manager] updateHeight: 230
>

Comment 2

[Jan Jongboom [:janjongboom] (inactive)]

So, is this bug gone with the landing of the font-inlining?

Comment 3

[Rudy Lu [:rudyl] (inactive after 2015/7/3)]

Attachment: log after font inlining

It seems the delay has been reduced to 100ms or so.

Comment 5

[Jan Jongboom [:janjongboom] (inactive)]

Awesome, the 100 ms. probably comes from event loop blocking when building up keyboard first time. Ah well.