cam: Print timestamp of captured buffers

Print the timestamp of the captured buffer in addition to the frame
rate, as this is more precise information that can help debugging issue.
The log changes from

Using camera \_SB_.PCI0.XHC_.RHUB.HS05-5:1.0-0bda:58f4
Capture until user interrupts by SIGINT
fps: 0.00 stream0 seq: 000000 bytesused: 169968
fps: 28.57 stream0 seq: 000002 bytesused: 170352
fps: 31.25 stream0 seq: 000003 bytesused: 170428
fps: 32.26 stream0 seq: 000004 bytesused: 170672
fps: 27.78 stream0 seq: 000005 bytesused: 170568

to

Using camera \_SB_.PCI0.XHC_.RHUB.HS05-5:1.0-0bda:58f4
Capture until user interrupts by SIGINT
93473.942525 (0.00 fps) stream0 seq: 000000 bytesused: 183940
93474.006528 (15.62 fps) stream0 seq: 000002 bytesused: 183512
93474.038525 (31.25 fps) stream0 seq: 000003 bytesused: 183760
93474.074530 (27.77 fps) stream0 seq: 000004 bytesused: 182704
93474.106581 (31.20 fps) stream0 seq: 000005 bytesused: 182768

While at it, compute the frame rate on the buffer timestamps instead of
sampling the clock in the request completion handler.

Signed-off-by: Laurent Pinchart <laurent.pinchart@ideasonboard.com>
Reviewed-by: Kieran Bingham <kieran.bingham@ideasonboard.com>
Reviewed-by: Niklas Söderlund <niklas.soderlund@ragnatech.se>

2 files changed, 13 insertions, 9 deletions

diff --git a/src/cam/capture.cpp b/src/cam/capture.cpp
index af9029b7..5510c009 100644
--- a/src/cam/capture.cpp
+++ b/src/cam/capture.cpp
@@ -5,7 +5,6 @@
  * capture.cpp - Cam capture
  */
 
-#include <chrono>
 #include <iomanip>
 #include <iostream>
 #include <limits.h>
@@ -159,14 +158,19 @@ void Capture::requestComplete(Request *request)
 
 	const Request::BufferMap &buffers = request->buffers();
 
-	std::chrono::steady_clock::time_point now = std::chrono::steady_clock::now();
-	double fps = std::chrono::duration_cast<std::chrono::milliseconds>(now - last_).count();
-	fps = last_ != std::chrono::steady_clock::time_point() && fps
-	    ? 1000.0 / fps : 0.0;
-	last_ = now;
+	/*
+	 * Compute the frame rate. The timestamp is arbitrarily retrieved from
+	 * the first buffer, as all buffers should have matching timestamps.
+	 */
+	uint64_t ts = buffers.begin()->second->metadata().timestamp;
+	double fps = ts - last_;
+	fps = last_ != 0 && fps ? 1000000000.0 / fps : 0.0;
+	last_ = ts;
 
 	std::stringstream info;
-	info << "fps: " << std::fixed << std::setprecision(2) << fps;
+	info << ts / 1000000000 << "."
+	     << std::setw(6) << std::setfill('0') << ts / 1000 % 1000000
+	     << " (" << std::fixed << std::setprecision(2) << fps << " fps)";
 
 	for (auto it = buffers.begin(); it != buffers.end(); ++it) {
 		const Stream *stream = it->first;
diff --git a/src/cam/capture.h b/src/cam/capture.h
index b4e39d51..0aebdac9 100644
--- a/src/cam/capture.h
+++ b/src/cam/capture.h
@@ -7,8 +7,8 @@
 #ifndef __CAM_CAPTURE_H__
 #define __CAM_CAPTURE_H__
 
-#include <chrono>
 #include <memory>
+#include <stdint.h>
 
 #include <libcamera/buffer.h>
 #include <libcamera/camera.h>
@@ -38,7 +38,7 @@ private:
 
 	std::map<const libcamera::Stream *, std::string> streamName_;
 	BufferWriter *writer_;
-	std::chrono::steady_clock::time_point last_;
+	uint64_t last_;
 
 	EventLoop *loop_;
 	unsigned int captureCount_;