From 944b051daa9fda620de798fd1d6d254d717dd579 Mon Sep 17 00:00:00 2001
From: Kamil Trzcinski <ayufan@ayufan.eu>
Date: Thu, 7 Apr 2022 12:44:36 +0200
Subject: [PATCH] Measure processing latency

---
 hw/buffer.h       | 1 +
 hw/buffer_lock.c  | 8 +++++---
 hw/buffer_queue.c | 1 +
 3 files changed, 7 insertions(+), 3 deletions(-)

diff --git a/hw/buffer.h b/hw/buffer.h
index a8d5d31..2d00552 100644
--- a/hw/buffer.h
+++ b/hw/buffer.h
@@ -17,6 +17,7 @@ typedef struct buffer_s {
   int mmap_reflinks;
   struct buffer_s *mmap_source;
   bool enqueued;
+  uint64_t enqueue_time_us;
 } buffer_t;
 
 buffer_t *buffer_open(const char *name, struct buffer_list_s *buf_list, int buffer);
diff --git a/hw/buffer_lock.c b/hw/buffer_lock.c
index 4b46c0e..e2b8b90 100644
--- a/hw/buffer_lock.c
+++ b/hw/buffer_lock.c
@@ -43,11 +43,13 @@ void buffer_lock_capture(buffer_lock_t *buf_lock, buffer_t *buf)
   buffer_use(buf);
   buf_lock->buf = buf;
   buf_lock->counter++;
-  buf_lock->buf_time_us = get_monotonic_time_us(NULL, NULL);
+  uint64_t last_lock_us = buf_lock->buf_time_us;
   uint64_t captured_time_us = get_time_us(CLOCK_FROM_PARAMS, NULL, &buf->v4l2_buffer.timestamp, 0);
-  E_LOG_DEBUG(buf_lock, "Captured buffer %s (refs=%d), frame=%d, delay=%.1f",
+  buf_lock->buf_time_us = get_monotonic_time_us(NULL, NULL);
+  E_LOG_DEBUG(buf_lock, "Captured buffer %s (refs=%d), frame=%d, processing_us=%.1f, frame_us=%.1f",
     dev_name(buf), buf ? buf->mmap_reflinks : 0, buf_lock->counter,
-    (buf_lock->buf_time_us - captured_time_us) / 1000.0f);
+    (buf_lock->buf_time_us - captured_time_us) / 1000.0f,
+    (buf_lock->buf_time_us - last_lock_us) / 1000.0f);
   pthread_cond_broadcast(&buf_lock->cond_wait);
   pthread_mutex_unlock(&buf_lock->lock);
 }
diff --git a/hw/buffer_queue.c b/hw/buffer_queue.c
index cece078..dea45a2 100644
--- a/hw/buffer_queue.c
+++ b/hw/buffer_queue.c
@@ -58,6 +58,7 @@ bool buffer_consumed(buffer_t *buf, const char *who)
 
     E_XIOCTL(buf, buf->buf_list->device->fd, VIDIOC_QBUF, &buf->v4l2_buffer, "Can't queue buffer.");
     buf->enqueued = true;
+    buf->enqueue_time_us = get_monotonic_time_us(NULL, NULL);
   }
 
   pthread_mutex_unlock(&buffer_lock);