commit 686f644f981badd481d8781bf80b221544df7b1f
author Shuzhen Wang <shuzhenwang@google.com> Tue Jun 20 16:16:04 2017 -0700
committer Shuzhen Wang <shuzhenwang@google.com> Fri Jun 23 12:05:16 2017 -0700
tree 59d934e011bfa583d9747ca7c994c5e0fe755cc7
parent 4226c955b64e672905b99b71f1b05798ecd30105

Camera: Add debug messages for camera latency

Log latency histogram of:
- processCaptureRequest call,
- dequeueBuffer call, and
- waiting time for handout count fall below max_buffers

Test: Camera CTS
Bug: 62651109
Change-Id: I5ee1cdb4139fa359f0887d6f6871884e28739340

services/camera/libcameraservice/device3/Camera3Device.cpp

diff --git a/services/camera/libcameraservice/device3/Camera3Device.cpp b/services/camera/libcameraservice/device3/Camera3Device.cpp
index 4571db8..e8b9b20 100644
--- a/services/camera/libcameraservice/device3/Camera3Device.cpp
+++ b/services/camera/libcameraservice/device3/Camera3Device.cpp
@@ -613,6 +613,11 @@
     }
     write(fd, lines.string(), lines.size());
 
+    if (mRequestThread != NULL) {
+        mRequestThread->dumpCaptureRequestLatency(fd,
+                "    ProcessCaptureRequest latency histogram:");
+    }
+
     {
         lines = String8("    Last request sent:\n");
         write(fd, lines.string(), lines.size());
@@ -3407,7 +3412,8 @@
         mCurrentPreCaptureTriggerId(0),
         mRepeatingLastFrameNumber(
             hardware::camera2::ICameraDeviceUser::NO_IN_FLIGHT_REPEATING_FRAMES),
-        mPrepareVideoStream(false) {
+        mPrepareVideoStream(false),
+        mRequestLatency(kRequestLatencyBinSize) {
     mStatusId = statusTracker->addComponent();
 }
 
@@ -3632,6 +3638,9 @@
     // The exit from any possible waits
     mDoPauseSignal.signal();
     mRequestSignal.signal();
+
+    mRequestLatency.log("ProcessCaptureRequest latency histogram");
+    mRequestLatency.reset();
 }
 
 void Camera3Device::RequestThread::checkAndStopRepeatingRequest() {
@@ -3848,11 +3857,14 @@
             mNextRequests.size());
 
     bool submitRequestSuccess = false;
+    nsecs_t tRequestStart = systemTime(SYSTEM_TIME_MONOTONIC);
     if (mInterface->supportBatchRequest()) {
         submitRequestSuccess = sendRequestsBatch();
     } else {
         submitRequestSuccess = sendRequestsOneByOne();
     }
+    nsecs_t tRequestEnd = systemTime(SYSTEM_TIME_MONOTONIC);
+    mRequestLatency.add(tRequestStart, tRequestEnd);
 
     if (useFlushLock) {
         mFlushLock.unlock();