Profiling and benchmarking support.

Makefile

@@ -19,7 +19,7 @@ export DSE_SCHEMA_URL ?= $(DSE_SCHEMA_REPO)/releases/download/v$(DSE_SCHEMA_VERS
 ###############
 ## DSE C Library.
 DSE_CLIB_REPO ?= https://github.com/boschglobal/dse.clib
-DSE_CLIB_VERSION ?= 1.0.5
+DSE_CLIB_VERSION ?= 1.0.6
 export DSE_CLIB_URL ?= $(DSE_CLIB_REPO)/archive/refs/tags/v$(DSE_CLIB_VERSION).zip
 
 
@@ -178,7 +178,7 @@ do-test_cmocka-run:
 do-test_pytest-run:
 	@-pip install -r tests/pytest/requirements.txt
 	redis-cli -h $(REDIS_HOST) ping
-	pytest -rx --asyncio-mode=strict -W ignore::DeprecationWarning tests/pytest
+	pytest -rx -x --asyncio-mode=strict -W ignore::DeprecationWarning tests/pytest
 
 do-clean:
 	@for d in $(SUBDIRS); do ($(MAKE) -C $$d clean ); done

dse/modelc/adapter/CMakeLists.txt

@@ -32,6 +32,7 @@ add_library(adapter OBJECT
     message.c
     simbus/adapter.c
     simbus/handler.c
+    simbus/profile.c
     simbus/states.c
     transport/endpoint.c
 #    transport/mq.c

dse/modelc/adapter/adapter.c

@@ -11,6 +11,7 @@
 #include <dse/clib/collections/hashmap.h>
 #include <dse/clib/util/strings.h>
 #include <dse/modelc/adapter/adapter.h>
+#include <dse/modelc/adapter/timer.h>
 #include <dse/modelc/adapter/adapter_private.h>
 #include <dse/modelc/adapter/message.h>
 #include <dse/modelc/controller/model_private.h>
@@ -23,6 +24,7 @@ typedef struct notify_spec_t {
     Adapter* adapter;
     notify(NotifyMessage_table_t) message;
     flatcc_builder_t* builder;
+    struct timespec   notifyrecv_ts;
 } notify_spec_t;
 
 
@@ -559,6 +561,10 @@ static int _adapter_model_ready(AdapterModel* am)
     notify(NotifyMessage_signals_add(builder, signals));
     notify(NotifyMessage_model_uid_add(builder, model_uids));
     notify(NotifyMessage_model_time_add(builder, am->model_time));
+    notify(
+        NotifyMessage_bench_model_time_ns_add(builder, am->bench_steptime_ns));
+    notify(NotifyMessage_bench_notify_time_ns_add(builder,
+        get_elapsedtime_ns(am->bench_notifyrecv_ts) - am->bench_steptime_ns));
     notify(NotifyMessage_ref_t) message = notify(NotifyMessage_end(builder));
     send_notify_message(adapter, message);
 
@@ -1036,6 +1042,7 @@ static int notify_model(void* value, void* data)
 {
     AdapterModel*  am = value;
     notify_spec_t* notify_data = data;
+    am->bench_notifyrecv_ts = notify_data->notifyrecv_ts;
     notify(NotifyMessage_table_t) message = notify_data->message;
     log_simbus("Notify/ModelStart <-- [%u]", am->model_uid);
     am->model_time = notify(NotifyMessage_model_time(message));
@@ -1086,6 +1093,7 @@ static void handle_notify_message(
     notify_spec_t notify_data = {
         .adapter = adapter,
         .message = notify_message,
+        .notifyrecv_ts = get_timespec_now(),
     };
     hashmap_iterator(&adapter->models, notify_model, true, &notify_data);
 }

dse/modelc/adapter/adapter.h

@@ -8,6 +8,7 @@
 
 #include <stdint.h>
 #include <stdbool.h>
+#include <time.h>
 #include <dse/clib/collections/set.h>
 #include <dse/clib/collections/hashmap.h>
 #include <dse/modelc/adapter/transport/endpoint.h>
@@ -64,16 +65,19 @@ typedef struct Adapter Adapter;
 
 typedef struct AdapterModel {
     /* Model properties. */
-    uint32_t model_uid;
-    double   model_time;
-    double   stop_time;
+    uint32_t        model_uid;
+    double          model_time;
+    double          stop_time;
     /* Channel properties. */
-    HashMap  channels;       // Collection of Channel, key is name.
-    char**   channels_keys;  // Cached result of hashmap_keys, update on
-                             // hashmap_set/remove.
-    uint32_t channels_length;
-
-    Adapter* adapter;  // back reference ?? Model Instance ??
+    HashMap         channels;       // Collection of Channel, key is name.
+    char**          channels_keys;  // Cached result of hashmap_keys, update on
+                                    // hashmap_set/remove.
+    uint32_t        channels_length;
+    /* Reference objects. */
+    Adapter*        adapter;
+    /* Benchmarking/Profiling. */
+    struct timespec bench_notifyrecv_ts;
+    uint64_t        bench_steptime_ns;
 } AdapterModel;
 
 
@@ -89,6 +93,10 @@ typedef struct Adapter {
 
     /* Endpoint container. */
     Endpoint* endpoint;
+
+    /* Benchmarking/Profiling. */
+    struct timespec bench_notifysend_ts;
+
     /* Private object supporting the operation of the Adapter.*/
     void* private;
 } Adapter;

dse/modelc/adapter/simbus/adapter.c

@@ -46,6 +46,9 @@ Adapter* simbus_adapter_create(void* endpoint, double bus_step_size)
     adapter->bus_adapter_model->adapter = adapter;
     adapter->bus_adapter_model->model_uid = adapter->endpoint->uid;
 
+    /* Benchmarking/Profiling. */
+    simbus_profile_init(bus_step_size);
+
     return adapter;
 }
 
@@ -112,4 +115,8 @@ void simbus_adapter_run(Adapter* adapter)
     }
 
     log_simbus("exit run loop");
+
+    /* Benchmarking/Profiling. */
+    simbus_profile_print_benchmarks();
+    simbus_profile_destroy();
 }

dse/modelc/adapter/simbus/handler.c

@@ -7,6 +7,7 @@
 #include <dse/clib/util/strings.h>
 #include <dse/modelc/adapter/simbus/simbus_private.h>
 #include <dse/modelc/adapter/adapter_private.h>
+#include <dse/modelc/adapter/timer.h>
 #include <dse/modelc/adapter/message.h>
 
 
@@ -620,6 +621,26 @@ void simbus_handle_notify_message(
     log_simbus("Notify/ModelReady <--");
     log_simbus("    model_time=%f", model_time);
 
+    /* Benchmarking/Profiling. */
+    if (adapter->bus_time > 0.0) {
+        struct timespec ref_ts = get_timespec_now();
+        uint64_t model_exec_time =
+            notify(NotifyMessage_bench_model_time_ns(notify_message));
+        uint64_t model_proc_time =
+            notify(NotifyMessage_bench_notify_time_ns(notify_message));
+        uint64_t network_time_ns =
+            get_deltatime_ns(adapter->bench_notifysend_ts, ref_ts) -
+            (model_proc_time + model_exec_time);
+        flatbuffers_uint32_vec_t vector =
+            notify(NotifyMessage_model_uid(notify_message));
+        size_t vector_len = flatbuffers_uint32_vec_len(vector);
+        for (uint32_t _vi = 0; _vi < vector_len; _vi++) {
+            uint32_t model_uid = flatbuffers_uint32_vec_at(vector, _vi);
+            simbus_profile_accumulate_model_part(model_uid, model_exec_time,
+                model_proc_time, network_time_ns, ref_ts);
+        }
+    }
+
     /* Handle embedded SignalVector tables. */
     notify(SignalVector_vec_t) vector =
         notify(NotifyMessage_signals(notify_message));
@@ -663,6 +684,17 @@ void simbus_handle_notify_message(
         double model_time = adapter->bus_time;
         double stop_time = model_time + adapter->bus_step_size;
 
+        /* Benchmarking/Profiling. */
+        if (adapter->bus_time > 0.0) {
+            struct timespec ref_ts = get_timespec_now();
+            uint64_t        simbus_cycle_total_ns =
+                get_deltatime_ns(adapter->bench_notifysend_ts, ref_ts);
+            simbus_profile_accumulate_cycle_total(
+                simbus_cycle_total_ns, ref_ts);
+        }
+        adapter->bench_notifysend_ts = get_timespec_now();
+
+        /* Notify/ModelStart. */
         resolve_and_notify(adapter, model_time, stop_time);
         simbus_models_to_start(am);
     }