Fix performance measurements

lib/aos/aos_urpc.c

@@ -23,6 +23,10 @@
 extern coreid_t my_core_id;
 extern rpc_handler_t rpc_handlers[RPC_MTYPE_COUNT];
 
+#ifdef PERFORMANCE_ENABLED
+struct performance_context p;
+#endif
+
 errval_t do_aos_urpc(
     struct aos_urpc *rpc, uintptr_t msg_type,
     struct capref arg_cap, size_t arg_size, uintptr_t arg0, uintptr_t arg1,
@@ -144,6 +148,12 @@ static void urpc_server_handler(void *arg) {
     // tell the other side that we are done
     urpc->meta->call_in_progress = false;
 
+#ifdef PERFORMANCE_ENABLED
+    if(msg_type == RPC_MTYPE_NOP) {
+        perf_add_now(&p, "done");
+    }
+#endif
+
     // Unblock the URPC thread
     thread_sem_post(&urpc->sem);
 }
@@ -168,7 +178,6 @@ errval_t aos_urpc_get_bootinfo(struct aos_urpc * rpc, struct bootinfo_serialized
     return SYS_ERR_OK;
 }
 
-struct performance_context p;
 int urpc_server(void *arg) {
     struct aos_urpc_server *urpc = arg;
     struct waitset *default_ws = get_default_waitset();
@@ -201,7 +210,9 @@ int urpc_server(void *arg) {
         waitset_chan_trigger_closure(default_ws, &chan, MKCLOSURE(urpc_server_handler, urpc));
 
 #ifdef PERFORMANCE_ENABLED
-        perf_add_now(&p, "triggered_closure");
+        if(type_nop) {
+            perf_add_now(&p, "triggered_closure");
+        }
 #endif
         
         // wait until the rpc is handled
@@ -209,7 +220,6 @@ int urpc_server(void *arg) {
 
 #ifdef PERFORMANCE_ENABLED
         if(type_nop) {
-            perf_add_now(&p, "done");
             perf_print(&p);
         }
 #endif

lib/aos/performance.c

@@ -11,6 +11,7 @@ void perf_init(struct performance_context *c, char *name) {
 
 inline void perf_add_measurement(struct performance_context *c, char *tag, systime_t timestamp)
 {
+    assert(c->count < PERFORMANCE_MEASUREMENT_COUNT_MAX);
     c->measurements[c->count].tag = tag;
     c->measurements[c->count].timestamp = timestamp;
     c->count++;

performance/performance_evaluation.py

@@ -39,12 +39,15 @@ def read_data(file):
         
 def build_dataseries(measurements, start_tag, end_tag):
     datapoints = []
+    measurements = list(filter(lambda m: start_tag == m["tag"] or end_tag == m["tag"], measurements))
 
     started_at = None
     for m in measurements:
         if started_at is None:
             if m["tag"] == start_tag:
                 started_at = m["timestamp"]
+            elif m["tag"] == end_tag:
+                print(f"[ERROR] Got end tag without start {end_tag}")
         else:
             if m["tag"] == end_tag:
                 datapoints.append(m["timestamp"] - started_at)
@@ -85,12 +88,11 @@ def main():
     # create plots for data series
     for key in dataset:
         d = dataset[key]
-        d.sort()
         p.clf()
         p.title(key)
         p.xlabel("datapoint index")
         p.ylabel("duration (cycles)")
-        p.scatter(range(len(d)), d)
+        p.plot(range(len(d)), d)
         p.savefig(os.path.join(out_dir, f"{key}.jpg"))
     
     p.clf()

usr/init/main.c

@@ -253,20 +253,22 @@ app_main(int argc, char *argv[]) {
 
     struct performance_context p;
     // measure performance measurement performance
-    for(size_t i = 0; i < 1000; ++i) {
+    for(size_t i = 0; i < 100; ++i) {
         perf_init(&p, "aos_performance");
         perf_add_now(&p, "start");
         perf_add_now(&p, "done");
         perf_print(&p);
+        barrelfish_usleep(10000);
     }
 
     // measure URPC performance
-    for(size_t i = 0; i < 1000; ++i) {
+    for(size_t i = 0; i < 100; ++i) {
         perf_init(&p, "aos_urpc_nop");
         perf_add_now(&p, "start");
         do_aos_urpc(&urpc_to_bsp, RPC_MTYPE_NOP, NULL_CAP, 0, 0, 0, NULL, NULL, NULL, NULL);
         perf_add_now(&p, "done");
         perf_print(&p);
+        barrelfish_usleep(10000);
     }
 #endif