Camera3: Make sure new metadata results signal other threads waiting

- Also adds a lot of logging around shuffling around metadata frames

Bug: 9007356
Change-Id: I4285f4f55b4b899ea4928d43062c705619c8248a

3 files changed, 39 insertions, 0 deletions

diff --git a/services/camera/libcameraservice/Camera3Device.cpp b/services/camera/libcameraservice/Camera3Device.cpp
index 6f4f4c8..1d38993 100644
--- a/services/camera/libcameraservice/Camera3Device.cpp
+++ b/services/camera/libcameraservice/Camera3Device.cpp
@@ -1329,6 +1329,10 @@ void Camera3Device::processCaptureResult(const camera3_capture_result *result) {
 
     // Finally, dispatch any 3A change events to listeners if we got metadata
 
+    if (result->result != NULL) {
+        mResultSignal.signal();
+    }
+
     if (result->result != NULL && listener != NULL) {
         if (new3aState.aeState != cur3aState.aeState) {
             ALOGVV("%s: AE state changed from 0x%x to 0x%x",
diff --git a/services/camera/libcameraservice/camera2/ProFrameProcessor.cpp b/services/camera/libcameraservice/camera2/ProFrameProcessor.cpp
index 257a45f..4012fc5 100644
--- a/services/camera/libcameraservice/camera2/ProFrameProcessor.cpp
+++ b/services/camera/libcameraservice/camera2/ProFrameProcessor.cpp
@@ -93,6 +93,9 @@ void ProFrameProcessor::processNewFrames(const sp<CameraDeviceBase> &device) {
     status_t res;
     ATRACE_CALL();
     CameraMetadata frame;
+
+    ALOGV("%s: Camera %d: Process new frames", __FUNCTION__, device->getId());
+
     while ( (res = device->getNextFrame(&frame)) == OK) {
 
         camera_metadata_entry_t entry;
@@ -124,6 +127,8 @@ void ProFrameProcessor::processNewFrames(const sp<CameraDeviceBase> &device) {
 
 bool ProFrameProcessor::processSingleFrame(CameraMetadata &frame,
                                            const sp<CameraDeviceBase> &device) {
+    ALOGV("%s: Camera %d: Process single frame (is empty? %d)",
+          __FUNCTION__, device->getId(), frame.isEmpty());
     return processListeners(frame, device) == OK;
 }
 
diff --git a/services/camera/libcameraservice/camera2/ZslProcessor3.cpp b/services/camera/libcameraservice/camera2/ZslProcessor3.cpp
index defcafc..f94b746 100644
--- a/services/camera/libcameraservice/camera2/ZslProcessor3.cpp
+++ b/services/camera/libcameraservice/camera2/ZslProcessor3.cpp
@@ -373,9 +373,15 @@ nsecs_t ZslProcessor3::getCandidateTimestampLocked(size_t* metadataIdx) const {
 
     size_t idx = 0;
     nsecs_t minTimestamp = -1;
+
+    size_t emptyCount = mFrameList.size();
+
     for (size_t j = 0; j < mFrameList.size(); j++) {
         const CameraMetadata &frame = mFrameList[j];
         if (!frame.isEmpty()) {
+
+            emptyCount--;
+
             camera_metadata_ro_entry_t entry;
             entry = frame.find(ANDROID_SENSOR_TIMESTAMP);
             if (entry.count == 0) {
@@ -387,7 +393,12 @@ nsecs_t ZslProcessor3::getCandidateTimestampLocked(size_t* metadataIdx) const {
             if (minTimestamp > frameTimestamp) {
 
                 entry = frame.find(ANDROID_CONTROL_AE_STATE);
+
                 if (entry.count == 0) {
+                    /**
+                     * This is most likely a HAL bug. The aeState field is
+                     * mandatory, so it should always be in a metadata packet.
+                     */
                     ALOGW("%s: ZSL queue frame has no AE state field!",
                             __FUNCTION__);
                     continue;
@@ -405,6 +416,25 @@ nsecs_t ZslProcessor3::getCandidateTimestampLocked(size_t* metadataIdx) const {
         }
     }
 
+    if (emptyCount == mFrameList.size()) {
+        /**
+         * This could be mildly bad and means our ZSL was triggered before
+         * there were any frames yet received by the camera framework.
+         *
+         * This is a fairly corner case which can happen under:
+         * + a user presses the shutter button real fast when the camera starts
+         *     (startPreview followed immediately by takePicture).
+         * + burst capture case (hitting shutter button as fast possible)
+         *
+         * If this happens in steady case (preview running for a while, call
+         *     a single takePicture) then this might be a fwk bug.
+         */
+        ALOGW("%s: ZSL queue has no metadata frames", __FUNCTION__);
+    }
+
+    ALOGV("%s: Candidate timestamp %lld (idx %d), empty frames: %d",
+          __FUNCTION__, minTimestamp, idx, emptyCount);
+
     if (metadataIdx) {
         *metadataIdx = idx;
     }