Forums - qmmf-server loosing frames

We are using the following hardware:
C610 Open Kit (Linux)
IMX577 Camera Board for C610/C410 Open Kit
IMX577 Camera Module

It seems like the skipped frames correlate with this kernel driver message about skipped frames:

/**
 * __cam_req_mgr_traverse()
 *
 * @brief    : Traverse through pd tables, it will internally cover all linked
 *             pd tables. Each pd table visited will check if idx passed to its
 *             in ready state. If ready means all devices linked to the pd table
 *             have this request id packet ready. Then it calls subsequent pd
 *             tbl with new idx. New idx value takes into account the delta
 *             between current pd table and next one.
 * @traverse_data: contains all the info to traverse through pd tables
 *
 * @return: 0 for success, negative for failure
 *
 */
static int __cam_req_mgr_traverse(struct cam_req_mgr_traverse *traverse_data)
{
...
        /* Check if req is ready or in skip mode or pd tbl is in skip mode */
        if (tbl->slot[curr_idx].state == CRM_REQ_STATE_READY ||
                traverse_data->in_q->slot[curr_idx].skip_idx == 1 ||
                tbl->skip_traverse > 0) {
....
        }
                /* This pd table is not ready to proceed with asked idx */
                CAM_INFO(CAM_CRM,
                        "Skip Frame: req: %lld not ready pd: %d open_req count: %d",
                        CRM_GET_REQ_ID(traverse_data->in_q, curr_idx),
                        tbl->pd,
                        traverse_data->open_req_cnt);
                SET_FAILURE_BIT(traverse_data->result, tbl->pd);
                return -EAGAIN;
        }
        return 0;
}

Every time I see the diff between frames being bigger than 0.033s, I see a message similar to this:

Mar 05 17:28:15 qcs610-odk-64 kernel: CAM_INFO: CAM-CRM: __cam_req_mgr_traverse: 262 Skip Frame: req: 503 not ready pd: 2 open_req count: 4

gtest.patch:

diff --git a/recorder/test/gtest/qmmf_gtest_common.cc b/recorder/test/gtest/qmmf_gtest_common.cc
index 0133b357..0aaa012a 100644
--- a/recorder/test/gtest/qmmf_gtest_common.cc
+++ b/recorder/test/gtest/qmmf_gtest_common.cc
@@ -425,7 +425,10 @@ void GtestCommon::SetUp() {
 
   recorder_status_cb_.event_cb = [this] (EventType event_type, void *event_data,
                                          size_t event_data_size) -> void
-      { RecorderCallbackHandler(event_type, event_data, event_data_size); };
+      {
+          std::cout << "######################### recorder_status_cb_.event_cb" << std::endl;
+          RecorderCallbackHandler(event_type, event_data, event_data_size);
+      };
 
   char prop_val[PROPERTY_VALUE_MAX];
   property_get(PROP_DUMP_BITSTREAM, prop_val, "0");
@@ -1028,6 +1031,7 @@ void GtestCommon::SnapshotCb(uint32_t camera_id,
                                BufferDescriptor buffer, MetaData meta_data) {
 
   TEST_INFO("%s Enter", __func__);
+  std::cout << "######### Enter SnapshotCb" << std::endl;
 
   size_t written_len;
 
@@ -1091,11 +1095,20 @@ void GtestCommon::SnapshotCb(uint32_t camera_id,
       }
 
       struct timeval tv;
+      static uint64_t tv_ms_prev = 0;
+      static uint64_t bts_prev = 0;
+      static uint64_t img_seq_prev = 0;
+
+      static uint64_t tv_ms_max = 0;
+      static uint64_t bts_max = 0;
+      static uint64_t img_seq_max = 0;
+
       gettimeofday(&tv, NULL);
       uint64_t tv_ms = (tv.tv_sec * 1000) + (tv.tv_usec / 1000);
       std::string file_path("/data/misc/qmmf/snapshot_");
       file_path += std::to_string(image_sequence_count) + "_";
       file_path += std::to_string(tv_ms) + ".";
+      file_path += std::to_string(buffer.timestamp) + ".";
       file_path += ext_str;
       FILE *file = fopen(file_path.c_str(), "w+");
       if (!file) {
@@ -1103,7 +1116,42 @@ void GtestCommon::SnapshotCb(uint32_t camera_id,
             file_path.c_str());
         goto FAIL;
       }
+      
+      std::cout << "### img seq: " << image_sequence_count << std::endl;
+      if (tv_ms_prev != 0) {
+          auto diff = (tv_ms-tv_ms_prev);
+          if((tv_ms-tv_ms_prev) > 40) {
+              std::cout << "### ERR tv_ms " << tv_ms << ", prev: " << tv_ms_prev
+                 << ", diff: " <<  (tv_ms-tv_ms_prev) << std::endl;
+              if (diff > tv_ms_max) {
+                  tv_ms_max = diff;
+                  std::cout << "#### New tv_ms_max: " << tv_ms_max << std::endl;
+              }
+          }
+          diff = (buffer.timestamp-bts_prev);
+          if(diff > 40000000) {
+              std::cout << "### ERR buf time " << buffer.timestamp << ", prev: " << bts_prev
+                 << ", diff: " << (buffer.timestamp-bts_prev) << std::endl;
+              if (diff > bts_max) {
+                  bts_max = diff;
+                  std::cout << "#### New bts_max: " << bts_max << std::endl;
+              }
+          }
+          diff=(image_sequence_count-img_seq_prev);
+          if(diff != 1) {
+              std::cout << "### ERR img seq " << image_sequence_count <<
+                  ", " << img_seq_prev << std::endl;
+              if (diff > img_seq_max) {
+                  tv_ms_max = diff;
+                  std::cout << "#### New img_seq_max: " << img_seq_max << std::endl;
+              }
+          }
+      }
+      tv_ms_prev = tv_ms;
+      bts_prev = buffer.timestamp;
+      img_seq_prev = image_sequence_count;
 
+#if 0
       written_len = fwrite(buffer.data, sizeof(uint8_t), buffer.size, file);
       TEST_INFO("%s: written_len =%d", __func__, written_len);
       if (buffer.size != written_len) {
@@ -1113,6 +1161,7 @@ void GtestCommon::SnapshotCb(uint32_t camera_id,
       }
       TEST_INFO("%s: Buffer(0x%p) Size(%u) Stored@(%s)\n", __func__,
                 buffer.data, written_len, file_path.c_str());
+#endif
 
       if (dump_thumbnail) {
         auto ret = DumpThumbnail(buffer, cam_buf_meta,
@@ -1128,6 +1177,7 @@ void GtestCommon::SnapshotCb(uint32_t camera_id,
       }
     }
   }
+
   // Return buffer back to recorder service.
   recorder_.ReturnImageCaptureBuffer(camera_id, buffer);
   TEST_INFO("%s Exit", __func__);
@@ -2348,6 +2398,7 @@ void GtestCommon::ConfigureImageParam() {
   image_param.image_format = snap_format_;
 
   if (snap_format_ == ImageFormat::kJPEG) {
+    std::cout << "##################### ImageFormat::kJPEG ?" << std::endl;
     image_param.width = snap_width_;
     image_param.height = snap_height_;
     image_param.image_quality = default_jpeg_quality_;
@@ -2359,6 +2410,7 @@ void GtestCommon::ConfigureImageParam() {
              snap_format_ == ImageFormat::kBayerRDI10BIT ||
              snap_format_ == ImageFormat::kBayerRDI12BIT ||
              snap_format_ == ImageFormat::kBayerRDI16BIT) {
+    std::cout << "##################### ImageFormat::kBayerRDI8BIT ?" << std::endl;
     // Configure max resolution for Bayer Snapshot.
     GtestCommon::GetMaxSupportedCameraRes(static_meta, image_param.width,
                                           image_param.height);
@@ -2369,6 +2421,7 @@ void GtestCommon::ConfigureImageParam() {
 
     if (snap_mode_ == SnapshotMode::kStillPlusRaw || snap_mode_
         == SnapshotMode::kVideoPlusRaw) {
+      std::cout << "##################### SnapshotMode::kStillPlusRaw ?" << std::endl;
       image_param.image_format = ImageFormat::kJPEG;
       image_param.width = snap_width_;
       image_param.height = snap_height_;
@@ -2376,6 +2429,8 @@ void GtestCommon::ConfigureImageParam() {
     }
   } else if (snap_format_ == ImageFormat::kNV12 ||
              snap_format_ == ImageFormat::kNV21) {
+
+    std::cout << "##################### ImageFormat::kNV12 ?" << std::endl;
     image_param.width = snap_width_;
     image_param.height = snap_height_;
     res_supported = GtestCommon::ValidateResFromStreamConfigs(
@@ -2391,6 +2446,7 @@ void GtestCommon::TakeSnapshot() {
   std::vector < CameraMetadata > meta_array;
   CameraMetadata meta;
 
+  std::cout << "######### TakeSnapshot" << std::endl;
   auto ret = recorder_.GetDefaultCaptureParam(camera_id_, meta);
   ASSERT_TRUE(ret == NO_ERROR);
 
@@ -2409,7 +2465,7 @@ void GtestCommon::TakeSnapshot() {
 
     if (snap_mode_ == SnapshotMode::kContinuous) {
       // Continuous Snapshot requires only one call to CaptureImage()
-      sleep(record_duration_ / 2);
+      sleep(record_duration_*4);
       break;
     }
     // Take Snapshot with every 5 sec.