IVGCVSW-6801 Add some timing information to ExecuteGraph.

* Modify all versions of ExecuteGraph to include timing information. This
  can give a rough guide as to how much overhead the driver is adding.

Signed-off-by: Colm Donelan <colm.donelan@arm.com>
Change-Id: Ie168e060c22b8417efa2ede0c9bdc7ef2631b913

1 files changed, 9 insertions, 1 deletions

diff --git a/ArmnnPreparedModel.cpp b/ArmnnPreparedModel.cpp
index 326351c0..41740435 100644
--- a/ArmnnPreparedModel.cpp
+++ b/ArmnnPreparedModel.cpp
@@ -14,6 +14,7 @@
 #include <OperationsUtils.h>
 #include <ValidateHal.h>
 
+#include <chrono>
 #include <cinttypes>
 
 #ifdef ARMNN_ANDROID_S
@@ -299,6 +300,8 @@ void ArmnnPreparedModel<HalVersion>::ExecuteGraph(
         CallbackContext_1_0 cb)
 {
     ALOGV("ArmnnPreparedModel::ExecuteGraph(...)");
+    // Capture the graph execution start time.
+    std::chrono::time_point<std::chrono::system_clock> graphExecutionStart = std::chrono::system_clock::now();
 
     DumpTensorsIfRequired("Input", inputTensors);
 
@@ -328,7 +331,6 @@ void ArmnnPreparedModel<HalVersion>::ExecuteGraph(
             status = m_Runtime->EnqueueWorkload(m_NetworkId, inputTensors, outputTensors,
                                                 importedInputIds, importedOutputIds);
         }
-
         if (status != armnn::Status::Success)
         {
             ALOGW("EnqueueWorkload failed");
@@ -365,6 +367,12 @@ void ArmnnPreparedModel<HalVersion>::ExecuteGraph(
         #endif
     }
 
+    // Log the total time in this call. This is a good number to compare to that printed out by
+    // RuntimeImpl::EnqueueWorkload. The difference should be the execution overhead of the driver.
+    ALOGI("ArmnnPreparedModel::ExecuteGraph Execution time = %lld µs",
+           std::chrono::duration_cast<std::chrono::microseconds>
+          (std::chrono::system_clock::now() - graphExecutionStart).count());
+
     cb.callback(V1_0::ErrorStatus::NONE, "ExecuteGraph");
 }