[Dolphin][Camera]Take 1.7s to stop Camera after click home button

RESOLVED WONTFIX
(Needinfo from 2 people)

Status

Firefox OS
Gaia::System
P1
blocker
RESOLVED WONTFIX
4 years ago
5 months ago

People

(Reporter: Xinhe Yan, Assigned: yaoyao.wu, NeedInfo)

Tracking

({perf})

unspecified
ARM
Gonk (Firefox OS)

Firefox Tracking Flags

(tracking-b2g:-, b2g-v1.4 affected, b2g-v2.0 wontfix)

Details

(Whiteboard: [c=effect p= s= u=1.4,dolphin][sprd315990][patner-blocker])

Attachments

(1 attachment)

(Reporter)

Description

4 years ago
There was a bug in sprd bugzilla. Our tester found it will take 1.4s to stop camera. Android only need 0.9s.
The data is not accurate. So I add some log.

It take 1.7s to call stop_preview(from gaia to gecko). CameraService only consume 0.3s to stop.
Can gecko optimize code to reduce time consume. 

06-05 02:58:41.945   107   107 E Gonk    : KeyEventDispatcher::DispatchKeyUpEvent  
06-05 02:58:42.025   107   107 E GeckoConsole: Content JS LOG at app://system.gaiamobile.org/js/app_window_manager.js:502 in awm_debug: [AppWindowManager][29.190]displaying homescreen
06-05 02:58:42.025   107   107 E GeckoConsole: Content JS LOG at app://system.gaiamobile.org/js/app_window_manager.js:502 in awm_debug: [AppWindowManager][29.191] current is app://camera.gaiamobile.org; next is homescreen
06-05 02:58:42.025   107   107 E GeckoConsole: Content JS LOG at app://system.gaiamobile.org/js/app_window_manager.js:502 in awm_debug: [AppWindowManager][29.191][object Object]
06-05 02:58:42.035   107   107 E GeckoConsole: Content JS LOG at app://system.gaiamobile.org/js/app_window_manager.js:502 in awm_debug: [AppWindowManager][29.191]homescreenfalse
06-05 02:58:42.035   107   107 E GeckoConsole: Content JS LOG at app://system.gaiamobile.org/js/app_window_manager.js:502 in awm_debug: [AppWindowManager][29.192]=== Active app now is: ,Homescreen,===


06-05 02:58:43.917   102   687 I         : L 2855, camera_stop_preview: timestamp = 51156. 
06-05 02:58:44.167   102   687 D CameraClient: CameraClient::~CameraClient E (pid 102, this 0xb8c23930)
06-05 02:58:44.167   102   687 D CameraClient: disconnect E (pid 102)
06-05 02:58:44.167   102   687 D CameraClient: camera is unlocked (mClientPid = 0), don't tear down hardware
06-05 02:58:44.167   102   687 D CameraClient: CameraClient::~CameraClient X (pid 102, this 0xb8c23930)
06-05 02:58:44.167   102   687 V CameraService: ~Client
06-05 02:58:44.167   102   687 D CameraService: CameraService::releaseSound ref=1
06-05 02:58:44.167   640   646 V GonkBufferQueue: ~GonkBufferQueue
06-05 02:58:44.167   102   687 V CameraService: Client::disconnect
06-05 02:58:44.167   102   687 V CameraService: BasicClient::disconnect
06-05 02:58:44.167   102   687 D CameraService: CameraService::removeClientByRemote E (pid 102)
06-05 02:58:44.167   102   687 D CameraService: CameraService::removeClientByRemote X (pid 102)
06-05 02:58:44.167   102   687 V CameraService: setCameraFree cameraId=0
06-05 02:58:44.167   102   687 V CameraService: ~BasicClient
(Reporter)

Comment 1

4 years ago
Dafeng, can you add gecko camera owner here?
Flags: needinfo?(Dafeng.Xu)
(Reporter)

Updated

4 years ago
Flags: needinfo?(james.zhang)
Hi Xinhe, can you post the patch used to generate the numbers in comment 0?
Flags: needinfo?(xinhe.yan)
(Reporter)

Comment 3

4 years ago
gecko:

diff --git a/widget/gonk/nsAppShell.cpp b/widget/gonk/nsAppShell.cpp
index 7ccb946..b455f74 100644
--- a/widget/gonk/nsAppShell.cpp
+++ b/widget/gonk/nsAppShell.cpp
@@ -73,7 +73,7 @@
 #include "GonkKeyMapping.h"
 
 #define LOG(args...)                                            \
-    __android_log_print(ANDROID_LOG_INFO, "Gonk" , ## args)
+    __android_log_print(ANDROID_LOG_ERROR, "Gonk" , ## args)
 #ifdef VERBOSE_LOG_ENABLED
 # define VERBOSE_LOG(args...)                           \
     __android_log_print(ANDROID_LOG_INFO, "Gonk" , ## args)
@@ -259,7 +259,7 @@ sendTouchEvent(UserInputData& data, bool* captured)
         for (i = 0; i < data.motion.touchCount; ++i)
             addDOMTouch(data, event, i);
     }
-
+    LOG("sendTouchEvent msg %d",msg);
     return nsWindow::DispatchInputEvent(event, captured);
 }
 
@@ -408,6 +408,7 @@ KeyEventDispatcher::DispatchKeyDownEvent()
 void
 KeyEventDispatcher::DispatchKeyUpEvent()
 {
+    LOG("KeyEventDispatcher::DispatchKeyUpEvent");
     DispatchKeyEventInternal(NS_KEY_UP);
 }

sprd camera log
vendor/sprd/open-source/libs/libcamera/sc8830/SprdOEMCamera.c   camera_stop_preview
No need change here. We already add log in code.
Flags: needinfo?(xinhe.yan)
Flags: needinfo?(james.zhang)
Thomas, need your help.
Flags: needinfo?(vliu)
Flags: needinfo?(ttsai)
status-b2g-v1.4: --- → affected

Comment 5

4 years ago
Hi Viral,

It seems Sprd had a profiling in InputEvent. Can you please have a look for this issue? Thanks
Flags: needinfo?(vliu) → needinfo?(vwang)

Comment 6

4 years ago
I would like to confirm the symptom described in this bug first.
I'm not sure if this bug is talking about camera stop too late or back to home too late.

If this is back to home case, normally it won't take over one second back to home.
it should only takes less than 20ms to pass the key event from EventHub to gaia, and we can back to home (from camera) around 1.0~1.2 second (in dolphin)

If it's too late to stop camera preview, we should compare with the timing we start to stop preview, not the timing we press the home key.
Flags: needinfo?(vwang)
(Assignee)

Updated

4 years ago
Duplicate of this bug: 1024953
Keywords: perf
Whiteboard: [c=effect p= s= u=]
It would be better if we could get a profile of the Camera and Homescreen app to see what's going on and where time is being spent. The profiling guide is here - https://developer.mozilla.org/en-US/docs/Mozilla/Performance/Profiling_with_the_Built-in_Profiler.
(Assignee)

Comment 9

4 years ago
get into camera app, press the home button wait until the idle display completely ,the log information is as follows:
06-17 05:10:06.451   106   106 E GeckoConsole: Content JS LOG at app://system.gaiamobile.org/js/hardware_buttons.js:279 in HardwareButtonsHomeState.prototype.enter: wei.gao_hardwarebuttonhomestate_enter_begin
06-17 05:10:07.191   106   106 E GeckoConsole: wei.gao_hardwarebutton_publish_dispatchEvent
06-17 05:10:07.191   106   106 E GeckoConsole: wei.gao_hide_begiin
06-17 05:10:07.201   106   106 E GeckoConsole: Content JS LOG at app://system.gaiamobile.org/js/cards_view.js:790 in cv_handleEvent: wei.gao_cvhanldevent_begin
06-17 05:10:07.251   106   106 E GeckoConsole: Content JS LOG at app://system.gaiamobile.org/js/cards_view.js:863 in cv_handleEvent: wei.gao_cvhanldevent_end
06-17 05:10:07.302   106   106 E GeckoConsole: Content JS LOG at app://system.gaiamobile.org/js/hardware_buttons.js:288 in HardwareButtonsHomeState.prototype.enter/this.timer<: wei.gao_hardwarebuttonHomestate_enter_end
06-17 05:10:07.822   106   106 E GeckoConsole: Content JS LOG at app://system.gaiamobile.org/js/app_window_manager.js:72 in awm_display: wei.gao_display_begin
06-17 05:10:07.882   106   106 E GeckoConsole: wei.gao_display()
06-17 05:10:07.892   106   106 E GeckoConsole: wei.gao_nokeyboard
06-17 05:10:07.902   106   106 E GeckoConsole: Content JS LOG at app://system.gaiamobile.org/js/app_window_manager.js:149 in awm_switchApp: wei.gao_switchApp_begin
06-17 05:10:07.942   106   106 E GeckoConsole: Content JS LOG at app://system.gaiamobile.org/js/app_window_manager.js:188 in awm_switchApp: wei.gao_switchapp_end
06-17 05:10:07.952   106   106 E GeckoConsole: Content JS LOG at app://system.gaiamobile.org/js/app_window_manager.js:135 in awm_display: wei.gao_display_end
(Assignee)

Comment 10

4 years ago
The  time-consuming tests of different applications are as follows :
Tester: 
Gallery: 1.41 
Email: 1.17 
PB: 1.09 
Browser: 1.14 

Contrast machine: 
Gallery: 0.92 
Email: 0.98 
PB: 0.9 
Browser: 0.85
(Assignee)

Comment 11

4 years ago
(In reply to yaoyao.wu from comment #9)
> get into camera app, press the home button wait until the idle display
> completely ,the log information is as follows:
> 06-17 05:10:06.451   106   106 E GeckoConsole: Content JS LOG at
> app://system.gaiamobile.org/js/hardware_buttons.js:279 in
> HardwareButtonsHomeState.prototype.enter:
> wei.gao_hardwarebuttonhomestate_enter_begin
> 06-17 05:10:07.191   106   106 E GeckoConsole:
> wei.gao_hardwarebutton_publish_dispatchEvent
> 06-17 05:10:07.191   106   106 E GeckoConsole: wei.gao_hide_begiin
> 06-17 05:10:07.201   106   106 E GeckoConsole: Content JS LOG at
> app://system.gaiamobile.org/js/cards_view.js:790 in cv_handleEvent:
> wei.gao_cvhanldevent_begin
> 06-17 05:10:07.251   106   106 E GeckoConsole: Content JS LOG at
> app://system.gaiamobile.org/js/cards_view.js:863 in cv_handleEvent:
> wei.gao_cvhanldevent_end
> 06-17 05:10:07.302   106   106 E GeckoConsole: Content JS LOG at
> app://system.gaiamobile.org/js/hardware_buttons.js:288 in
> HardwareButtonsHomeState.prototype.enter/this.timer<:
> wei.gao_hardwarebuttonHomestate_enter_end
> 06-17 05:10:07.822   106   106 E GeckoConsole: Content JS LOG at
> app://system.gaiamobile.org/js/app_window_manager.js:72 in awm_display:
> wei.gao_display_begin
> 06-17 05:10:07.882   106   106 E GeckoConsole: wei.gao_display()
> 06-17 05:10:07.892   106   106 E GeckoConsole: wei.gao_nokeyboard
> 06-17 05:10:07.902   106   106 E GeckoConsole: Content JS LOG at
> app://system.gaiamobile.org/js/app_window_manager.js:149 in awm_switchApp:
> wei.gao_switchApp_begin
> 06-17 05:10:07.942   106   106 E GeckoConsole: Content JS LOG at
> app://system.gaiamobile.org/js/app_window_manager.js:188 in awm_switchApp:
> wei.gao_switchapp_end
> 06-17 05:10:07.952   106   106 E GeckoConsole: Content JS LOG at
> app://system.gaiamobile.org/js/app_window_manager.js:135 in awm_display:
> wei.gao_display_end


The process involves two functions :
(1)display: function awm_display(origin, openAnimation, closeAnimation):the function takes0.13s
(2)HardwareButtons.prototype.handleEvent = function hb_handleEvent(evt):the function takes1.371s
 the function calls function HardwareButtonsHomeState.prototype.enter = function() {
  console.log("wei.gao_hardwarebuttonhomestate_enter_begin");  
  this.timer = setTimeout(function() {
      /**
       * When the user holds Home button more than HOLD_INTERVAL.
       * @event HardwareButtonsHomeState#holdhome
       */
      this.hardwareButtons.publish('holdhome');
      navigator.vibrate(50);
      this.hardwareButtons.setState('base');
      console.log("wei.gao_hardwarebuttonHomestate_enter_end");
    }.bind(this), this.hardwareButtons.HOLD_INTERVAL);
  }; 
this.hardwareButtons.HOLD_INTERVAL=750, here set 0.75s delay.
Time spent in other functions relatively less. 

So,I wondere if we can set  hardwareButtons.HOLD_INTERVAL from 750 to a smaller value to reduce the time spent.

Comment 12

4 years ago
Assigning to Yaoyao since you're actively looking into this issue. We recommend gathering a profile to identify exactly where time is being lost per Mason's guidance in comment 8.

FxOS Performance Team
Assignee: nobody → yaoyao.wu
Priority: -- → P2
Whiteboard: [c=effect p= s= u=] → [c=effect p= s= u=dolphin]
(Assignee)

Comment 13

4 years ago
(In reply to Mike Lee [:mlee] from comment #12)
> Assigning to Yaoyao since you're actively looking into this issue. We
> recommend gathering a profile to identify exactly where time is being lost
> per Mason's guidance in comment 8.
> 
> FxOS Performance Team
Hi Mike,
According to Mason's guidance in comment 8, I gathering profile_captured.sym, but "Error 0 occurred uploading your file", so I upload profile_captured.sym as an attachment instead of sharing with URL.I'm not sure whether it's feasible.
Thanks.
(Assignee)

Comment 14

4 years ago
Created attachment 8443849 [details]
profile_captured.sym

Updated

4 years ago
Flags: needinfo?(ttsai)

Updated

4 years ago
Flags: needinfo?(Dafeng.Xu)
I tested 5 times on Buri V1.4. The average time is less than 1s. So this is specific to dolphin.

Actually, dolphin camera does has a lot of performance issues, such as picture saving is slow, camera launch slow and so on.
per comment 15
blocking-b2g: --- → 1.4?
Triage: From comment 15, plusing for perf issues.
blocking-b2g: 1.4? → 1.4+
From comment 11, were you able to try reducing the HOLD_INTERVAL to see if that improved things? Thanks!
Flags: needinfo?(yaoyao.wu)
(Assignee)

Comment 19

4 years ago
(In reply to Mason Chang [:mchang] from comment #18)
> From comment 11, were you able to try reducing the HOLD_INTERVAL to see if
> that improved things? Thanks!
Hi Mason,
    By reducing the HOLD_INTERVA doesn't improve things.Because the timer was cleared later.
Ben has some ideas on this issue.
Flags: needinfo?(yaoyao.wu) → needinfo?(ben.song)

Comment 20

4 years ago
When app_window_manager.js response home type of event,the code would be switched between the frame of current app and new app,the process would invoke function aw__showScreenshotOverlay(),in which the frame of new app would be screenshot,but for the background of homescreen is transparent,not need an overlay and card view,however we has provided some function unnecessary which will consume 0.15s at least.This problem may has been solved in bug 878003,isn't it ?

Updated

4 years ago
Flags: needinfo?(ben.song)

Updated

4 years ago
Severity: normal → blocker
Status: NEW → ASSIGNED
Priority: P2 → P1

Updated

4 years ago
Whiteboard: [c=effect p= s= u=dolphin] → [c=effect p= s= u=1.4,dolphin]

Comment 21

4 years ago
During stoping Camera or other apps after short-click home button,function waitforNextPaint() would be invoked twice which consumes almost 0.5s only once,it means time-consume of this function is a big problem,it would bring bad experience to users.Through the mozilla API i know the effect of the function is waiting for next event of MozAfterPaint ,but i don't know whether could remove this function in the code,and i don't know the special effect of MozAfterPaint event,could you help me? 

thanks
Flags: needinfo?(eperelman)

Comment 22

4 years ago
Apologies, but I am not familiar with this event. Redirecting to Gandalf who may know.
Flags: needinfo?(eperelman) → needinfo?(gandalf)
Where is the code that is guarded by MozAfterPaint?
Flags: needinfo?(gandalf)
I am marking 2.0 as wontfix here as the issues seem to be dolphin specific and might be risky for 2.0 at this point., we should however land this on central/master as necessary.
status-b2g-v2.0: --- → wontfix

Comment 25

4 years ago
(In reply to Zibi Braniecki [:gandalf] from comment #23)
> Where is the code that is guarded by MozAfterPaint?

function of waitforNextPaint in the file of browser_mixin, in the module of system.

Updated

4 years ago
Component: Gaia::Camera → Gaia::System
Is the viewfinder using the hardware compositor not triggering paint events, which makes the waitForNextPaint() call take arbitrarily long.

Comment 27

4 years ago
(In reply to Mike Habicher [:mikeh] from comment #26)
> Is the viewfinder using the hardware compositor not triggering paint events,
> which makes the waitForNextPaint() call take arbitrarily long.

But during the switch of homescreen and another app,this function will be invoked twice normally.This is a big problem.
Whiteboard: [c=effect p= s= u=1.4,dolphin] → [c=effect p= s= u=1.4,dolphin][sprd315990][patner-blocker]

Comment 28

4 years ago
Hi Yaoyao,

Mind if you can provide some update on this bug?
Flags: needinfo?(yaoyao.wu)
(Assignee)

Comment 29

4 years ago
(In reply to Ivan Tsay (:ITsay) from comment #28)
> Hi Yaoyao,
> 
> Mind if you can provide some update on this bug?

Hi ,
Of course I don't mind ,please do as you like.
Hi Yaoyao an Ben.Song, may I know if you have any further findings and progress on this? 
Thanks !
Flags: needinfo?(ben.song)

Comment 31

4 years ago
(In reply to Rachelle Yang [:ryang][ryang@mozilla.com] from comment #30)
> Hi Yaoyao an Ben.Song, may I know if you have any further findings and
> progress on this? 
> Thanks !

Dear Rachella,
   I find the function of waitforNextPaint is unuseful and it would take too much time.In my opinion,the function's effect like a example that a worker want to rest half hour at most, and during his rest if his boss assign him a new task, so he must stop rest and continue with new task,but if not receive new task he would continue with old task.Function waitforNextPaint is like this,in its rest much time has been consumed and may happen that last work of old task would be lose for the event of system would not be fire.
Flags: needinfo?(ben.song)

Updated

4 years ago
Flags: needinfo?(ryang)
Hi Jason, with the patch of Bug985772, do you retest the bug?
Thanks!
Flags: needinfo?(ryang) → needinfo?(jason.liu)

Comment 33

4 years ago
This bug hasn't been updated for a week. Is it still a partner blocker?

Comment 34

4 years ago
[Blocking Requested - why for this release]:
blocking-b2g: 1.4+ → 1.4?

Comment 35

4 years ago
The latest test result base on 31.4 :
1.24   1.19   1.23   AVG:1.22s
Flags: needinfo?(jason.liu)

Comment 36

4 years ago
Andoird 7715GA and android 6821 time is 0.9s.
Hi Jason, Could you please provide the data of Buri 1.4? 
I suppose we should take Buri 1.4 as performance benchmark. Thanks !
Flags: needinfo?(jason.liu)
(In reply to Jason.Liu from comment #35)
> The latest test result base on 31.4 :
> 1.24   1.19   1.23   AVG:1.22s

 it has been improved from 1.7 to 1.2, there isnt much more we can do to improve here. Please profile and find if improvements can be done at your end.

Comment 39

4 years ago
(In reply to Rachelle Yang [:ryang][ryang@mozilla.com] from comment #37)
> Hi Jason, Could you please provide the data of Buri 1.4? 
> I suppose we should take Buri 1.4 as performance benchmark. Thanks !

Hi  Rachelle:
    I answer the question according to jason‘s idea.

    First,we don't have Buri1.4 .we can't do that test.
    Second,what customers care about is ffos_dolphin_7715 compared with android_dolphin_7715,not comparison parameters between ffos machines. Andoird 7715GA and android 6821 time is 0.9s but ffos 7715GA is 1.22s。

Comment 40

4 years ago
(In reply to Wayne Chang [:wchang] from comment #38)
> (In reply to Jason.Liu from comment #35)
> > The latest test result base on 31.4 :
> > 1.24   1.19   1.23   AVG:1.22s
> 
>  it has been improved from 1.7 to 1.2, there isnt much more we can do to
> improve here. Please profile and find if improvements can be done at your
> end.

Hi Wayne:
    We are pleased that the performance has been improved.
    Can you summarize our measures,so we can close this bug.
I think bug 1040049 also can improve performance.
We'll use 1.3 zoom-in animation.
Depends on: 1040049
Improvement shown from other bugs, removing the nom here.
blocking-b2g: 1.4? → ---
Hi all,
   After investigating, we found not only camera app takes long time to back cardview but also every apps need more time to back cardview than other devices.
   
   We also found "Dolphin" costs much more time than other devices for getScreenshot and "apps transition" needs 2 times too.

   Since getScreenshot relies on hardware specs, I don't think gaia can help on it.
   So we will focus on reducing "apps transition" time to improve this issue, but we suspect it also belong to graphic performance(hardware) issue too.

   Thanks.
After tracing the code, we found that window manager in system app will try to ensure homescreen full repainted and then start switching to cards view. In Dolphin, however, it spends about 1 ~ 1.5 seconds on waiting for homescreen to be ready. 

This number doubles if the foreground app is camera but we have no idea why. A possible reason is that homescreen will take more time to wake up from background if its process has been swapped out.

Anyway, it may be an option to improve the repainting performance of homescreen app if we want to lower the delay.

Updated

3 years ago
tracking-b2g: --- → -

Comment 45

5 months ago
Firefox OS is not being worked on
Status: ASSIGNED → RESOLVED
Last Resolved: 5 months ago
Resolution: --- → WONTFIX
You need to log in before you can comment on or make changes to this bug.