Closed Bug 995303 Opened 6 years ago Closed 2 years ago

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

Categories

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

ARM
Gonk (Firefox OS)
defect

Tracking

(tracking-b2g:-, b2g-v1.3T affected)

RESOLVED WONTFIX
tracking-b2g -
Tracking Status
b2g-v1.3T --- affected

People

(Reporter: rdandu, Unassigned)

References

Details

(Keywords: perf, Whiteboard: [c=progress p= s= u=tarako][sprd307067][tarako_only])

Attachments

(3 files)

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
Keywords: perf
Summary: [Tarako]Camera cold launch from lock screen is tool long: 2.9 seconds → [Tarako] Camera cold launch from lock screen is too long: 2.9 seconds
Whiteboard: perf
Component: Performance → Gaia::Camera
Whiteboard: perf → [c= p= s= u=]
Assignee: nobody → eperelman
Whiteboard: [c= p= s= u=] → [c=progress p= s= u=]
Priority: -- → P2
Whiteboard: [c=progress p= s= u=] → [c=progress p=3 s= u=]
Status: NEW → ASSIGNED
Whiteboard: [c=progress p=3 s= u=] → [c=progress p=3 s= u=tarako]
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.
blocking-b2g: --- → 1.3T?
Whiteboard: [c=progress p=3 s= u=tarako] → [c=progress p=3 s= u=tarako][sprd307067][partner-blocker][tarako_only]
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.
Flags: needinfo?(nhirata.bugzilla)
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.
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.
Flags: needinfo?(nhirata.bugzilla) → needinfo?(bbajaj)
(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.
blocking-b2g: 1.3T? → -
Flags: needinfo?(bbajaj)
(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.
Flags: needinfo?(dflanagan)
Arvin,
cd gaia
git log apps/camera/

or
cd gaia
git log | grep dflanagan@mozilla.com
As I mentioned in Comment 1, the bug in question is bug 991297. I'll mark it for see also as well.
Flags: needinfo?(dflanagan)
See Also: → 991297
(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.
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
Naoki, I did my profiling by attaching to the Pre-allocated process. Is that the method you used for profiling?
Alive or Vivien, do you have anyone who could look into lockscreen bottlenecks on the Gecko side for improving this interaction?
Flags: needinfo?(alive)
Flags: needinfo?(21)
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?
Flags: needinfo?(alive)
(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 ?
Flags: needinfo?(21)
Whiteboard: [c=progress p=3 s= u=tarako][sprd307067][partner-blocker][tarako_only] → [c=progress p=3 s= u=tarako][sprd307067][tarako_only]
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.
Flags: needinfo?(alive)
Flags: needinfo?(21)
(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.
Flags: needinfo?(alive)
Then you're likely want to speak with Mike Habicher for the Gecko side.
Flags: needinfo?(21)
Mike, would you be able to have someone look into this in an future sprint?
Flags: needinfo?(mhabicher)
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?
Flags: needinfo?(mhabicher) → needinfo?(hkoka)
I'll take a look.
Assignee: eperelman → mhabicher
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.
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.
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.
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?
Flags: needinfo?(rdandu)
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
Flags: needinfo?(rdandu)
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.
Assignee: mhabicher → nobody
Component: Gaia::Camera → Gaia::System::Lockscreen
renominating the bug based on partner feedback.
blocking-b2g: - → 1.3T?
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.
blocking-b2g: 1.3T? → ---
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.  :)
Flags: needinfo?(eperelman)
Flags: needinfo?(hkoka)
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
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()).
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.
Flags: needinfo?(eperelman)
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!
Whiteboard: [c=progress p=3 s= u=tarako][sprd307067][tarako_only] → [c=progress p= s= u=tarako][sprd307067][tarako_only]
Any update on this? This bug blocks tarako mass production. Customer wants this to be fixed. Please help.
Severity: normal → blocker
Priority: P2 → P1
(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?
Flags: needinfo?(wchang)
So where are we with the bug?
Flags: needinfo?(wchang)
Flags: needinfo?(kkuo)
Flags: needinfo?(kkuo)
See Also: → 1068393
tracking-b2g: --- → -
Firefox OS is not being worked on
Status: ASSIGNED → RESOLVED
Closed: 2 years ago
Resolution: --- → WONTFIX
You need to log in before you can comment on or make changes to this bug.