From 416b1ae80ba2cb8b6a8d76b3a2aacdeecdc1451e Mon Sep 17 00:00:00 2001 From: xiaosuGW Date: Wed, 11 Aug 2021 13:35:44 -0500 Subject: [PATCH] 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 | 2 +- runtime/include/perf_window.h | 34 ++++++++++++++++++++++- runtime/include/perf_window_t.h | 3 +- runtime/include/sandbox_set_as_complete.h | 6 +++- runtime/src/admissions_info.c | 12 ++++---- runtime/src/module.c | 2 +- 6 files changed, 49 insertions(+), 10 deletions(-) diff --git a/runtime/include/admissions_info.h b/runtime/include/admissions_info.h index d0c2786..9cd2612 100644 --- a/runtime/include/admissions_info.h +++ b/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); diff --git a/runtime/include/perf_window.h b/runtime/include/perf_window.h index e4ebfc6..5e7b5d5 100644 --- a/runtime/include/perf_window.h +++ b/runtime/include/perf_window.h @@ -1,22 +1,26 @@ #pragma once #include +#include #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); +} diff --git a/runtime/include/perf_window_t.h b/runtime/include/perf_window_t.h index 4d39af4..e45c612 100644 --- a/runtime/include/perf_window_t.h +++ b/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; diff --git a/runtime/include/sandbox_set_as_complete.h b/runtime/include/sandbox_set_as_complete.h index 805e784..efd061e 100644 --- a/runtime/include/sandbox_set_as_complete.h +++ b/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); diff --git a/runtime/src/admissions_info.c b/runtime/src/admissions_info.c index cee9bf3..c70eff1 100644 --- a/runtime/src/admissions_info.c +++ b/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); } diff --git a/runtime/src/module.c b/runtime/src/module.c index a371a64..fc7230e 100644 --- a/runtime/src/module.c +++ b/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 */