Closed Bug 914916 Opened 6 years ago Closed 6 years ago

Camera App First Time Launch Latency

Categories

(Firefox OS Graveyard :: Gaia::Camera, defect, P1)

ARM
Gonk (Firefox OS)
defect

Tracking

(blocking-b2g:koi+)

RESOLVED DUPLICATE of bug 915083
1.2 C3(Oct25)
blocking-b2g koi+

People

(Reporter: skamat, Assigned: mikeh)

References

Details

(Keywords: perf, Whiteboard: [c=progress p= s= u=1.2])

Based on partner expectations, First time launch latency for Camera app is 1400ms. The bug is to track the user story for 1.2 releases. 1.2 should cause no regression from 1.1.
Just to clarify: I tested on unagi yesterday, and saw a launch (touch-to-viewfinder-active) latency of 1.8s. Looking at the execution profile, there doesn't appear to be much we can do to pare this down--at least on unagi*. I'm looking at hamachi next. What device are you specifically talking about?

-----
*Unagi is a particularly bad case: initializing the hardware takes ~700ms, during which time the device is idle waiting for the camera.
Flags: needinfo?(skamat)
Also, is the 1400ms from comment 0 our current performance, or our target?
Blocks: 915068
Blocks: 915083
Whiteboard: PERF [UCID:Perf7, FT:Perf, KOI:P1] [c= u=1.2][oslo] → PERF [c=progress u=1.2][oslo]
It took some time, but I have numbers for hamachi as well. With the following build:
- gecko: m-c:23708fab4a39
- gaia: master:70800e30b4e8f1162d32bcff4228216b524ffee2

...the hamachi camera takes even longer to start up. The touch-event-to-app-launch time is comparable to unagi (about 300ms), and the time to request the camera is slightly faster (650ms vs 800ms); but the time to initialize the hardware is more than twice as long!  unagi takes ~750ms; hamachi takes over 2 seconds.

Will dig into this to see where all that time is going.
Using the patch in attachment 803691 [details] [diff] [review] in bug 821841, I get the following timestamp report:
+--- Profile report for 'Camera.Startup':
|    0. +      0 us, mozilla::CameraControlImpl::CameraControlImpl(uint32_t, nsIThread*, uint64_t):35
|    1. +   8657 us, nsresult mozilla::nsGonkCameraControl::Init():249
|    2. +2087038 us, nsresult mozilla::nsGonkCameraControl::Init():251
|    3. +  41405 us, nsresult mozilla::nsGonkCameraControl::Init():308
|    4. +  61730 us, virtual nsresult mozilla::CameraControlImpl::GetPreviewStream(mozilla::idl::CameraSize, nsICameraPreviewStreamCallback*, nsICameraErrorCallback*):385
|    5. + 114285 us, virtual nsresult mozilla::CameraControlImpl::StartPreview(mozilla::DOMCameraPreview*):452
|    6. + 487035 us, virtual nsresult mozilla::nsGonkCameraControl::StartPreviewImpl(mozilla::StartPreviewTask*):687
| dtor. +  33320 us
+--- End of report for 'Camera.Startup'

The huge delay in (2) corresponds to calling GonkCameraHardware::Connect():

  CAMERA_PROFILER_STAMP(mStartupProfiler);
  mCameraHw = GonkCameraHardware::Connect(this, mCameraId);
  CAMERA_PROFILER_STAMP(mStartupProfiler);

...which is basically a wrapper for:

  sp<Camera> camera = Camera::connect(aCameraId);
Further to comment 4, the only visibility into ::connect() available in hamachi is through the GonkNativeWindow::dequeueBuffer() callback. Timestamping this shows that we spend ~50ms acquiring preview buffers.
Summary: [B2G] [Performance User Story][v1.2]: Camera App First Time Launch Latency → Camera App First Time Launch Latency
Whiteboard: PERF [c=progress u=1.2][oslo] → [c=progress u=1.2][oslo]
Hema - you're engineering mgr for media so starting with you to find a proper owner.
Assignee: nobody → hkoka
Assignee: hkoka → sotaro.ikeda.g
Duplicate of this bug: 913299
Status: NEW → ASSIGNED
Whiteboard: [c=progress u=1.2][oslo] → [c=progress p= s= u=1.2][oslo]
GonkNativeWindow uses ImageBrdge for gralloc buffer allocation. In master, since gfx layer refactoring, compositor's rendering transaction is more optimized than b2g18. gralloc buffer allocation is more blocked by the rendering transaction. It is difficult to improve the gralloc buffer allocation by using current way (allocation via imagebridge). Therefore as a temporary solution, I am going to create temporary implementation that allocate gralloc buffer without using ImageBridge.
Actually I am going to implement it by using android Binder IPC, because the Binder IPC is multithreaded IPC. gecko's IPC runs only in fixed thread.

http://elinux.org/Android_Binder
Sotaro, how much of a difference do you think this will make? Although I couldn't rebuild the camera driver, I put timestamps into the dequeueBuffer() callback that gets called during initialize(), and it looks like we only spend ~60ms (on hamachi) across those 7 calls.
Priority: -- → P1
(In reply to Mike Habicher [:mikeh] from comment #9)
> Sotaro, how much of a difference do you think this will make? Although I
> couldn't rebuild the camera driver, I put timestamps into the
> dequeueBuffer() callback that gets called during initialize(), and it looks
> like we only spend ~60ms (on hamachi) across those 7 calls.

Thanks for the comment. It just come from the experience of b2g18. I am going to check about the bottle neck in current master.
(In reply to Mike Habicher [:mikeh] from comment #2)
> Also, is the 1400ms from comment 0 our current performance, or our target?

It's the target. The perf targets are based on our shipping device numbers (with v1.0.1 and 1.1). We do not want degrade from those numbers.
Flags: needinfo?(skamat)
(In reply to Sotaro Ikeda [:sotaro] from comment #10)
> Thanks for the comment. It just come from the experience of b2g18. I am
> going to check about the bottle neck in current master.

I confirmed that the gralloc buffer allocation is not major delay. I stop the current implementation.
mikeh, can you take the bug? It's better you continue the profiling and fix.
Assignee: sotaro.ikeda.g → nobody
Assigning to Mike H per Sotari's comment #13 and his current work on Camera launch latency.
Assignee: nobody → mhabicher
Whiteboard: [c=progress p= s= u=1.2][oslo] → [c=progress p= s= u=1.2]
Target Milestone: 1.2 FC (16sep) → ---
Target Milestone: --- → 1.2 C3(Oct25)
Lets track the latency issues in one bug: 915083
Status: ASSIGNED → RESOLVED
Closed: 6 years ago
Resolution: --- → DUPLICATE
Duplicate of bug: 915083
Hema Koka deleted the linked story in Pivotal Tracker
You need to log in before you can comment on or make changes to this bug.