1. move operations for perf_window out of the admission control macro. 2. memory printf the execution times when window is full

runtime/include/admissions_info.h

@@ -10,6 +10,6 @@ struct admissions_info {
 	uint64_t           relative_deadline; /* Relative deadline in cycles. This is duplicated state */
 };
 
-void admissions_info_initialize(struct admissions_info *self, int percentile, uint64_t expected_execution,
+void admissions_info_initialize(struct admissions_info *self, char* module_name, int percentile, uint64_t expected_execution,
                                 uint64_t relative_deadline);
 void admissions_info_update(struct admissions_info *self, uint64_t execution_duration);

runtime/include/perf_window.h

@@ -1,22 +1,26 @@
 #pragma once
 
 #include <stdint.h>
+#include <assert.h>
 
 #include "lock.h"
 #include "perf_window_t.h"
 #include "runtime.h"
 #include "worker_thread.h"
+#include "memlogging.h"
+#include "panic.h"
 
 /**
  * Initializes perf window
  * @param self
  */
 static inline void
-perf_window_initialize(struct perf_window *self)
+perf_window_initialize(struct perf_window *self, char* module_name)
 {
 	assert(self != NULL);
 
 	LOCK_INIT(&self->lock);
+	strncpy(self->name, module_name, 32);
 	self->count = 0;
 	memset(&self->by_duration, 0, sizeof(struct execution_node) * PERF_WINDOW_BUFFER_SIZE);
 	memset(&self->by_termination, 0, sizeof(uint16_t) * PERF_WINDOW_BUFFER_SIZE);
@@ -158,3 +162,31 @@ perf_window_get_count(struct perf_window *self)
 
 	return self->count;
 }
+
+/**
+ * Print the items in the perf window
+ */
+static inline void
+perf_window_print(struct perf_window *self) 
+{
+	assert(self != NULL);
+	if (self->count % PERF_WINDOW_BUFFER_SIZE != 0) { return; }
+	/* Not need to hold lock because this operation won't add/delete the array */
+	float min = self->by_duration[0].execution_time/1000.0;
+	float max = self->by_duration[PERF_WINDOW_BUFFER_SIZE-1].execution_time/1000.0;
+	uint64_t sum = 0;
+        float fifty_p = self->by_duration[PERF_WINDOW_BUFFER_SIZE * 50 / 100].execution_time/1000.0;	
+        float seventy_p = self->by_duration[PERF_WINDOW_BUFFER_SIZE * 70 / 100].execution_time/1000.0;	
+        float eighty_p = self->by_duration[PERF_WINDOW_BUFFER_SIZE * 80 / 100].execution_time/1000.0;	
+        float nighty_p = self->by_duration[PERF_WINDOW_BUFFER_SIZE * 90 / 100].execution_time/1000.0;	
+        float nighty_night_p = self->by_duration[PERF_WINDOW_BUFFER_SIZE * 99 / 100].execution_time/1000.0;	
+
+	mem_log("module %s perf window:\n", self->name);
+	for (int i = 0; i < PERF_WINDOW_BUFFER_SIZE; i++) {
+		sum += self->by_duration[i].execution_time;
+                mem_log("%f,", self->by_duration[i].execution_time/1000.0);
+        }
+	mem_log("\n");
+	float avg = (sum/(float)PERF_WINDOW_BUFFER_SIZE)/1000.0;
+	mem_log("min:%f,max:%f,fifty_p:%f,seventy_p:%f,eighty_p:%f,nighty_p:%f,nighty_night_p:%f,avg:%f\n", min,max,fifty_p,seventy_p,eighty_p,nighty_p,nighty_night_p, avg);
+}

runtime/include/perf_window_t.h

@@ -5,7 +5,7 @@
 #include "lock.h"
 
 /* Should be Power of 2! */
-#define PERF_WINDOW_BUFFER_SIZE 16
+#define PERF_WINDOW_BUFFER_SIZE 256 
 
 #if ((PERF_WINDOW_BUFFER_SIZE == 0) || (PERF_WINDOW_BUFFER_SIZE & (PERF_WINDOW_BUFFER_SIZE - 1)) != 0)
 #error "PERF_WINDOW_BUFFER_SIZE must be power of 2!"
@@ -24,6 +24,7 @@ struct execution_node {
 };
 
 struct perf_window {
+	char                  name[32];
 	struct execution_node by_duration[PERF_WINDOW_BUFFER_SIZE];
 	uint16_t              by_termination[PERF_WINDOW_BUFFER_SIZE];
 	uint64_t              count;

runtime/include/sandbox_set_as_complete.h

@@ -10,7 +10,9 @@
 #include "sandbox_state.h"
 #include "sandbox_summarize_page_allocations.h"
 #include "sandbox_types.h"
+#include "perf_window.h"
 
+extern uint32_t runtime_processor_speed_MHz;
 /**
  * Transitions a sandbox from the SANDBOX_RETURNED state to the SANDBOX_COMPLETE state.
  * Adds the sandbox to the completion queue
@@ -49,9 +51,11 @@ sandbox_set_as_complete(struct sandbox *sandbox, sandbox_state_t last_state)
 	runtime_sandbox_total_decrement(last_state);
 
 	/* Admissions Control Post Processing */
-	admissions_info_update(&sandbox->module->admissions_info, sandbox->running_duration);
+	admissions_info_update(&sandbox->module->admissions_info, sandbox->running_duration / runtime_processor_speed_MHz);
 	admissions_control_subtract(sandbox->admissions_estimate);
 
+	perf_window_print(&sandbox->module->admissions_info.perf_window);
+
 	/* Terminal State Logging */
 	sandbox_print_perf(sandbox);
 	sandbox_mem_print_perf(sandbox);

runtime/src/admissions_info.c

@@ -1,14 +1,18 @@
 #include "admissions_info.h"
+#include "perf_window.h"
 #include "debuglog.h"
 
+extern __thread uint64_t generic_thread_lock_duration;
+extern __thread uint64_t generic_thread_lock_longest;
 /**
  * Initializes perf window
  * @param self
  */
 void
-admissions_info_initialize(struct admissions_info *self, int percentile, uint64_t expected_execution,
+admissions_info_initialize(struct admissions_info *self, char* module_name, int percentile, uint64_t expected_execution,
                            uint64_t relative_deadline)
 {
+	perf_window_initialize(&self->perf_window, module_name);
 #ifdef ADMISSIONS_CONTROL
 	assert(relative_deadline > 0);
 	assert(expected_execution > 0);
@@ -17,8 +21,6 @@ admissions_info_initialize(struct admissions_info *self, int percentile, uint64_
 	debuglog("Initial Estimate: %lu\n", self->estimate);
 	assert(self != NULL);
 
-	perf_window_initialize(&self->perf_window);
-
 	if (unlikely(percentile < 50 || percentile > 99)) panic("Invalid admissions percentile");
 	self->percentile = percentile;
 
@@ -39,13 +41,13 @@ admissions_info_initialize(struct admissions_info *self, int percentile, uint64_
 void
 admissions_info_update(struct admissions_info *self, uint64_t execution_duration)
 {
-#ifdef ADMISSIONS_CONTROL
 	struct perf_window *perf_window = &self->perf_window;
 
 	LOCK_LOCK(&self->perf_window.lock);
 	perf_window_add(perf_window, execution_duration);
+#ifdef ADMISSIONS_CONTROL
 	uint64_t estimated_execution = perf_window_get_percentile(perf_window, self->percentile, self->control_index);
 	self->estimate = admissions_control_calculate_estimate(estimated_execution, self->relative_deadline);
-	LOCK_UNLOCK(&self->perf_window.lock);
 #endif
+	LOCK_UNLOCK(&self->perf_window.lock);
 }

runtime/src/module.c

@@ -240,7 +240,7 @@ module_new(char *name, char *path, int32_t argument_count, uint32_t stack_size,
 
 	/* Admissions Control */
 	uint64_t expected_execution = (uint64_t)expected_execution_us * runtime_processor_speed_MHz;
-	admissions_info_initialize(&module->admissions_info, admissions_percentile, expected_execution,
+	admissions_info_initialize(&module->admissions_info, name, admissions_percentile, expected_execution,
 	                           module->relative_deadline);
 
 	/* Request Response Buffer */