From 9ce1ced92d4b3d6b7e8165e5ee208912e166574a Mon Sep 17 00:00:00 2001
From: Hayodea Hekol <hayodea@protonmail.com>
Date: Thu, 20 Nov 2025 03:26:43 -0400
Subject: [PATCH] PcloudStimBuff,IoUringAssmEngn: add frame assembly perf
 profiling

We now time the frame assembly sequence.
---
 .../livoxGen1/ioUringAssemblyEngine.cpp         | 17 +++++++++++++++++
 stimBuffApis/livoxGen1/ioUringAssemblyEngine.h  |  7 +++++++
 .../livoxGen1/pcloudStimulusProducer.cpp        | 17 +++++++++--------
 3 files changed, 33 insertions(+), 8 deletions(-)

diff --git a/stimBuffApis/livoxGen1/ioUringAssemblyEngine.cpp b/stimBuffApis/livoxGen1/ioUringAssemblyEngine.cpp
index a174426..7912452 100644
--- a/stimBuffApis/livoxGen1/ioUringAssemblyEngine.cpp
+++ b/stimBuffApis/livoxGen1/ioUringAssemblyEngine.cpp
@@ -432,6 +432,9 @@ public:
 		// Initialize loop with number of slots
 		context->loop = AsynchronousLoop(engine.frameAssemblyDesc->numSlots);
 
+		// Record assembly start time
+		engine.assemblyStartTime = std::chrono::high_resolution_clock::now();
+
 		/**	FIXME:
 		 * I'm suspicious of this std::bind return object here. What if us
 		 * setting it to null inside of stop() doesn't actually cause the
@@ -528,6 +531,10 @@ public:
 		 */
 		// Ensure we only execute once using atomic exchange
 		if (context->handlerExecuted.exchange(true)) { return; }
+		// Record assembly end time
+		context->engine.assemblyEndTime =
+			std::chrono::high_resolution_clock::now();
+
 		// Cancel the timer, stop the engine and process frame, if any.
 		context->engine.assemblyCycleComplete();
 
@@ -851,5 +858,15 @@ void IoUringAssemblyEngine::printSlotBytes(size_t slotIndex, size_t nBytes)
 	}
 }
 
+std::chrono::milliseconds IoUringAssemblyEngine::getAssemblyDuration() const
+{
+	auto duration = assemblyEndTime - assemblyStartTime;
+	if (duration.count() < 0)
+	{
+		return std::chrono::milliseconds(0);
+	}
+	return std::chrono::duration_cast<std::chrono::milliseconds>(duration);
+}
+
 } // namespace stim_buff
 } // namespace smo
diff --git a/stimBuffApis/livoxGen1/ioUringAssemblyEngine.h b/stimBuffApis/livoxGen1/ioUringAssemblyEngine.h
index 97ccc55..5d5563d 100644
--- a/stimBuffApis/livoxGen1/ioUringAssemblyEngine.h
+++ b/stimBuffApis/livoxGen1/ioUringAssemblyEngine.h
@@ -45,6 +45,9 @@ public:
 	static bool compactionIsNeeded(uint32_t nSucceeded, uint32_t nTotal)
 		{ return nSucceeded != 0 && nTotal != 0 && nSucceeded != nTotal; }
 
+	// Get assembly execution duration in milliseconds
+	std::chrono::milliseconds getAssemblyDuration() const;
+
 private:
 	typedef std::function<void(void*, int)> resetAndAssembleFrameCbFn;
 	void resetAndAssembleFrame(resetAndAssembleFrameCbFn onCqeReady);
@@ -94,6 +97,10 @@ private:
 	std::random_device randomDevice;
 	std::mt19937 randomGenerator;
 
+	// Timestamp tracking for assembly execution
+	std::chrono::high_resolution_clock::time_point assemblyStartTime;
+	std::chrono::high_resolution_clock::time_point assemblyEndTime;
+
 	void fillUnAssembledSlotsWithDummyDgrams();
 	void randomDummySlotFiller(AsynchronousLoop& loop);
 	void onEventfdRead(
diff --git a/stimBuffApis/livoxGen1/pcloudStimulusProducer.cpp b/stimBuffApis/livoxGen1/pcloudStimulusProducer.cpp
index 8db55d6..435846b 100644
--- a/stimBuffApis/livoxGen1/pcloudStimulusProducer.cpp
+++ b/stimBuffApis/livoxGen1/pcloudStimulusProducer.cpp
@@ -413,16 +413,17 @@ public:
 
 		if (!success) {
 			std::cerr << __func__ << ": Failed to compact and collate frame" << std::endl;
-		} else {
-			std::cout << __func__ << ": Successfully compacted and collated frame" << std::endl;
+		} else
+		{
+			// Print execution durations
+			auto assemblyDuration = pcloudProducer.ioUringAssemblyEngine.getAssemblyDuration();
+			auto compactDuration = pcloudProducer.openClCollatingAndMeshingEngine.getCompactKernelDuration();
+			auto collateDuration = pcloudProducer.openClCollatingAndMeshingEngine.getCollateKernelDuration();
+			std::cout << __func__ << ": Successfully compacted and collated frame: assemblyDuration=" << assemblyDuration.count()
+				<< "ms, compactKernelDuration=" << compactDuration.count()
+				<< "ms, collateKernelDuration=" << collateDuration.count() << "ms" << std::endl;
 		}
 
-		// Print kernel execution durations
-		auto compactDuration = pcloudProducer.openClCollatingAndMeshingEngine.getCompactKernelDuration();
-		auto collateDuration = pcloudProducer.openClCollatingAndMeshingEngine.getCollateKernelDuration();
-		std::cout << __func__ << ": compactKernelDuration=" << compactDuration.count()
-			<< "ms, collateKernelDuration=" << collateDuration.count() << "ms" << std::endl;
-
 		callOriginalCallback();
 	}
 };