995303 - [Tarako] Camera cold launch from lock screen is too long: 2.9 seconds

Status: RESOLVED WONTFIX

(Firefox OS Graveyard :: Gaia::System::Lockscreen, defect, P1)

Description

[Ravi Dandu]

Attachment: Tarako_Performance_TPE-v0.1.pdf

Tarako testing has shows the Camera cold launch from lock to be 2.9 seconds. This needs to be reduced to 1 second.
From a User Experience point of view:
1) 140ms cause/effect timeline: Camera Launch animation should be within 140 ms for humans to see effect of pressing the button
2) 1s perception of progress: Camera ready should happen within this timeline. We should try to do without loading screen if possible. Camera is highly time sensitive. So should be within 1s for human perception of progress timeline

Attached are the Tarako test results

Comment 1

[:Eli Perelman]

Attachment: Lockscreen to camera profile

In profiling the interaction from the lockscreen to the camera app launch, it appears we have already completed quite a bit of optimization from the Gaia side to improve the performance and perceived responsiveness. I have attached a profile that may help shed light on some improvements on the Gecko side, but from speaking with several others, it is believed that the main bottleneck is with the camera initialization in the hardware layer that needs optimizing.

In order to help meet our goals for giving visual cues to the user that something is occurring, I have decided that the landed patch from 991297 works well. This is the final piece from the Gaia side as far as the camera is concerned to give the user the perception of progress.

Comment 2

[bhavana bajaj [:bajaj]]

NI on :nhirata to help reproduce this, :fabrice tried it locally and said it is something we could live with, wanted to get QA opinion here.

Comment 3

[David Flanagan [:djf]]

Note also that a recent patch of mine (I forget the bug number) added a spinner to the camera startup. It is only displayed for the last .5s or so of the loading time, but it helps some.

The bulk of the delay here is the time required to unlock the phone and launch the camera app. If regular camera startup time is acceptable, then the startup time from the lockscreen is a lockscreen bug, not a camera app bug.  Maybe there is something that could be done to start the camera sooner without any lockscreen animations.

Also note that if there is a passcode on the lockscreen, then the camera app runs as part of the system app and startup is noticeably quicker.  I point this out again to say that the component is wrong on this bug. It is a lockscreen bug, not a camera bug.

Having said all that, this really does not seem like a blocker to me.

Comment 4

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

I can reproduce the bug, and QA can live with this for the first launch.
If there are speed improvements that don't cause regressions, of course we would take it.

Comment 5

[bhavana bajaj [:bajaj]]

(In reply to Naoki Hirata :nhirata (please use needinfo instead of cc) from comment #4)
> I can reproduce the bug, and QA can live with this for the first launch.
> If there are speed improvements that don't cause regressions, of course we
> would take it.

Thanks Naoki, based on the bug comments and your feedback this definitely is a nice-to-have but not a blocker for release.

Comment 6

[helloarvin]

(In reply to David Flanagan [:djf] from comment #3)
> Note also that a recent patch of mine (I forget the bug number) added a
> spinner to the camera startup. It is only displayed for the last .5s or so
> of the loading time, but it helps some.
> 
> The bulk of the delay here is the time required to unlock the phone and
> launch the camera app. If regular camera startup time is acceptable, then
> the startup time from the lockscreen is a lockscreen bug, not a camera app
> bug.  Maybe there is something that could be done to start the camera sooner
> without any lockscreen animations.
> 
> Also note that if there is a passcode on the lockscreen, then the camera app
> runs as part of the system app and startup is noticeably quicker.  I point
> this out again to say that the component is wrong on this bug. It is a
> lockscreen bug, not a camera bug.
> 
> Having said all that, this really does not seem like a blocker to me.

Dear David,

Could you please help to tell me the bug number for which a spinner to the camera startup added, so that i can verify if the patch had been merged into v1.3t or not?

Thanks for your kindly help.

Comment 7

[James Zhang (Spreadtrum)]

Arvin,
cd gaia
git log apps/camera/

or
cd gaia
git log | grep [e-mail]

Comment 8

[:Eli Perelman]

As I mentioned in Comment 1, the bug in question is bug 991297. I'll mark it for see also as well.

Comment 9

[helloarvin]

(In reply to Eli Perelman, :Eli from comment #8)
> As I mentioned in Comment 1, the bug in question is bug 991297. I'll mark it
> for see also as well.

Get it and just for double check.

Thank you.

Comment 10

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

I captured 2 profiles as best I could.  (profile requires the process to already be running to capture it) Camera from the homescreen and Camera from the lockscreen:

https://drive.google.com/file/d/0B_0LdM1CVycIazV5SHp2ckdfZDA/edit?usp=sharing
https://drive.google.com/file/d/0B_0LdM1CVycIVURKN1lLRjM5WjA/edit?usp=sharing

Comment 11

[:Eli Perelman]

Naoki, I did my profiling by attaching to the Pre-allocated process. Is that the method you used for profiling?

Comment 12

[:Eli Perelman]

Alive or Vivien, do you have anyone who could look into lockscreen bottlenecks on the Gecko side for improving this interaction?

Comment 13

[(inactive after 6/18) Alive Kuo [:alive]]

I have no idea for gecko, but
1. Do you mean secure camera(lockscreen passcode is enabled) or normal camera(passcode is not enabled)?
2. What's the launch time of normal camera app, from lockscreen and from homescreen?

Comment 14

[Vivien Nicolas (:vingtetun) (:21) - (NOT reading bugmails, needinfo? please)]

(In reply to Eli Perelman, :Eli from comment #12)
> Alive or Vivien, do you have anyone who could look into lockscreen
> bottlenecks on the Gecko side for improving this interaction?

I assume s/Gecko/Gaia ?

As David/Alive noticed we used to open different camera panels, depending if there is a passcode or not on the lockscreen.

Which one is too slow ? Is there one that is fast, enough ? If yes, is it OK to just opened this one all the time on Tarako and this can be worked on on master for future releases ?

Comment 15

[:Eli Perelman]

Alive/Vivien,

Apologies, but I am indeed wondering if you could point me in the right direction to someone who can look at this from the Gecko side.

Comment 16

[(inactive after 6/18) Alive Kuo [:alive]]

(In reply to Eli Perelman, :Eli from comment #15)
> Alive/Vivien,
> 
> Apologies, but I am indeed wondering if you could point me in the right
> direction to someone who can look at this from the Gecko side.

I think it's performance team but since this is not a blocker and we have limited resource, I couldn't ensure who could be assigned to. You should ask a PM to prioritize it. If you need a name -- I have no idea and I don't think I could assign to someone.

Comment 17

[Vivien Nicolas (:vingtetun) (:21) - (NOT reading bugmails, needinfo? please)]

Then you're likely want to speak with Mike Habicher for the Gecko side.

Comment 18

[:Eli Perelman]

Mike, would you be able to have someone look into this in an future sprint?

Comment 19

[:Eli Perelman]

Sorry, this should have been addressed to Hema. Hema, we have exhausted our resources for solving this on the performance team. Could you please prioritize this for a future sprint?

Comment 20

[Mike Habicher [:mikeh] (high bugzilla latency)]

I'll take a look.

Comment 21

[Mike Habicher [:mikeh] (high bugzilla latency)]

I just flashed a recent build onto my Tarako:
- gecko: b2g-inbound:a882f6508aa9
- gaia: master:68c3018b71e3a70a9f6575b3ab87b945539f4cc5

...and the camera viewfinder is broken. The Camera starts, and I can take a few pictures before the camera fails.

Comment 22

[Mike Habicher [:mikeh] (high bugzilla latency)]

Attachment: logcat of Tarako camera problems

Comment 23

[Mike Habicher [:mikeh] (high bugzilla latency)]

Attachment 8428833 [details] shows:

05-26 17:39:52.130    88  1286 V SprdCameraOEM: camera_encoder_thread S. 0x41bd9000 0x7c00000 0x0 0x0
05-26 17:39:52.130    88  1286 V SprdCameraOEM: camera_encoder_thread ,jpg tmp 0x41bd9000 0x7c00000
05-26 17:39:52.130    88  1286 E SprdCameraHardware: Fail to GetPmem().
05-26 17:39:52.130    88  1286 E SprdCameraHardware: fail to FreePmem: NULL is camera_memory->release.
05-26 17:39:52.130    88  1286 E SprdCameraOEM: Fail to encode jpeg picture by SC8800G2 HW.
05-26 17:39:52.130    88  1286 V SprdCameraHardware: FreePmem: NULL
05-26 17:39:52.140    88  1286 V SprdCameraHardware: FreePmem: NULL
05-26 17:39:52.140    88  1286 V SprdCameraHardware: FreePmem: NULL
05-26 17:39:52.140    88  1286 V SprdCameraHardware: FreePmem: NULL
05-26 17:39:52.140    88  1286 V SprdCameraHardware: FreePmem: NULL
05-26 17:39:52.140    88  1286 E SprdCameraHardware: SprdCameraHardware::camera_cb: @CAMERA_EXIT_CB_FAILURE(1084272820) in state QCS_WAITING_JPEG.

Looks like the camera library/driver is running out of memory. I'll file a separate bug for this new issue.

Comment 24

[Mike Habicher [:mikeh] (high bugzilla latency)]

As mentioned in the no-longer-blocking bug 1016043, the Tarako camera problems don't exist in the 1.3t branch, so please disregard comment 21, comment 22, and comment 23.

With a passcode set, it looks like it takes the Camera app ~3 seconds to launch from a passworded Lockscreen--the exact same time it takes to launch from the Homescreen.

Will try to get better numbers with a HFR camera.

Comment 25

[Mike Habicher [:mikeh] (high bugzilla latency)]

Just looking into the Tarako performance metrics in attachment 8405480 [details], and have a few comments and questions, below.

(In reply to rdandu from comment #0)
> 
> Tarako testing has shows the Camera cold launch from lock to be 2.9 seconds.
> This needs to be reduced to 1 second.

I don't think this is feasible. Android's cold-launch time for the Camera app outside of the Lockscreen--usually the fastest time we can manage--is already slower than ours, and our time is 2.6s. In the Lockscreen, things are tighter, but Android still takes ~2.1s to launch.

> From a User Experience point of view:
> 1) 140ms cause/effect timeline: Camera Launch animation should be within 140
> ms for humans to see effect of pressing the button

I agree. On my Tarako, when I touch the camera button on the Lockscreen, the transition starts almost immediately. I haven't measured the time (yet), but it certainly feels responsive. If the visual feedback is still happening too late, we should consider animating the camera button.

> 2) 1s perception of progress: Camera ready should happen within this
> timeline. We should try to do without loading screen if possible. Camera is
> highly time sensitive. So should be within 1s for human perception of
> progress timeline

As I mentioned above, I don't think this is feasible for Tarako; I'm not even sure it's feasible for high-end devices like the Flame (though I haven't measured it).

What's a more realistic launch-time goal?

Comment 26

[:Eli Perelman]

Mike, according to our perception of progress goals [1], if it's not possible within 1s to complete the task at hand, then we need to give visual indicators that something is in the works, e.g. a Sync UI [2]. Basically, if we can't be finished with camera ready by 1.25s (which should be the correct goal), then there should be a spinner or some visual indicator that its waiting to complete.

From what I understand, :djf had a spinner implementation in place that should cover this interaction, from bug 991297, see comment #3.

[1] https://developer.mozilla.org/en-US/Apps/Build/Performance/Firefox_OS_app_responsiveness_guidelines
[2] https://developer.mozilla.org/en-US/Apps/Build/Performance/UI_Synchronicity

Comment 27

[Mike Habicher [:mikeh] (high bugzilla latency)]

Eli, thanks for clarifying.

I've just tested Tarako and Flame side-by-side, and Tarako is definitely slower to launch the passcoded-Lockscreen camera, and is noticeably slower to provide any visual feedback that it is going to.

Once Tarako's Lockscreen -starts- to open the camera, though, it happens relatively quickly, so I'm guessing the delay is part of the Lockscreen. Someone who understands that part of the system should take a look.

Comment 28

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

renominating the bug based on partner feedback.

Comment 29

[bhavana bajaj [:bajaj]]

Clearing it for now until we have more information from partner, based on fabrice's initial investigation there is nothing much  we can do here.

Comment 30

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

eli, I used : https://developer.mozilla.org/en-US/docs/Mozilla/Performance/Profiling_with_the_Built-in_Profiler

I'm not aware how you did that, if you teach me, I will be willing to reprofile.  Also please needinfo? me in regards to a response if you want quicker feedback.  :)

Comment 31

[Mike Habicher [:mikeh] (high bugzilla latency)]

A little bit of camera stack timing: unlike hamachi, which takes ~2s to connect to the camera service, tarako takes ~1s the -first- time after a reboot, and 350 to 450ms thereafter. Whether or not this happens in the app or the passworded-Lockscreen camera makes no difference.

Some data:
19:36:57 ➜  ~  adb logcat -v threadtime | grep "Camera::connect()"      

-- app
05-28 23:12:31.950   357   415 I Gecko   : Camera::connect() took 1058.770874 milliseconds
05-28 23:12:38.180   357   415 I Gecko   : Camera::connect() took 456.153931 milliseconds
05-28 23:12:42.660   357   415 I Gecko   : Camera::connect() took 453.631775 milliseconds
05-28 23:12:46.630   357   415 I Gecko   : Camera::connect() took 372.431946 milliseconds
05-28 23:12:49.950   357   415 I Gecko   : Camera::connect() took 379.635468 milliseconds
05-28 23:12:57.310   424   470 I Gecko   : Camera::connect() took 385.215851 milliseconds
05-28 23:13:01.640   424   470 I Gecko   : Camera::connect() took 421.816956 milliseconds
05-28 23:13:06.140   424   470 I Gecko   : Camera::connect() took 391.375153 milliseconds
05-28 23:13:15.980   477   507 I Gecko   : Camera::connect() took 369.788116 milliseconds
05-28 23:13:22.580   477   507 I Gecko   : Camera::connect() took 395.717499 milliseconds
05-28 23:13:58.180   543   568 I Gecko   : Camera::connect() took 455.082611 milliseconds

-- passworded Lockscreen
05-28 23:14:36.750   595   622 I Gecko   : Camera::connect() took 374.466400 milliseconds
05-28 23:14:47.890   630   647 I Gecko   : Camera::connect() took 340.545166 milliseconds

Comment 32

[Mike Habicher [:mikeh] (high bugzilla latency)]

Looking at the |adb logcat -v threadtime| output, I can see from the first camera library call to the start of delivery of viewfinder frames is ~990ms (of which, 440ms is spent in ::connect()).

Comment 33

[:Eli Perelman]

Naoki, I mostly just follow the instructions from the link you posted, with the exception that if I want to profile the app before I launch it, I write the command to use the ID of the pre-allocated process. So if the pre-allocated process is 1024:

./profile.sh ps
  PID Name
----- ----------------
  845 b2g              profiler not running
  893 (Nuwa)           profiler not running
  909 Homescreen       profiler not running
  937 Messages         profiler not running
 1024 (Preallocated a  profiler not running

I'll profile with:

./profile.sh start -p b2g -i 10 && ./profile.sh start -p 1024

and then launch the camera.

Comment 34

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

Oh!  I will use that method in the future for launch profiling.  Thanks!  Since you already have the profile, I guess there's no need to do it for this bug.  I should also load it up in cleopatra.  That might make things easier...  Thanks for the info!

Comment 35

[Peipei Cheng (needinfo if you need my action)]

Any update on this? This bug blocks tarako mass production. Customer wants this to be fixed. Please help.

Comment 36

[bhavana bajaj [:bajaj]]

(In reply to pcheng from comment #35)
> Any update on this? This bug blocks tarako mass production. Customer wants
> this to be fixed. Please help.

Wayne, this is being requested out of no where after a month, can you help here?

Comment 37

[Wayne Chang [:wchang]]

So where are we with the bug?

Comment 38

[BMO Automation]

Firefox OS is not being worked on