diff --git a/runtime/include/admissions_control.h b/runtime/include/admissions_control.h new file mode 100644 index 0000000..8e03440 --- /dev/null +++ b/runtime/include/admissions_control.h @@ -0,0 +1,123 @@ +#pragma once + +#include +#include +#include +#include + +#include "debuglog.h" +#include "client_socket.h" + +#define ADMISSIONS_CONTROL_GRANULARITY 1000000 + +/* + * Unitless estimate of the instantaneous fraction of system capacity required to complete all previously + * admitted work. This is used to calculate free capacity as part of admissions control + * + * The estimated requirements of a single admitted request is calculated as + * estimated execution time (cycles) / relative deadline (cycles) + * + * These estimates are incremented on request acceptance and decremented on request completion (either + * success or failure) + */ +extern _Atomic uint64_t admissions_control_admitted; +extern uint64_t admissions_control_capacity; + +static inline void +admissions_control_initialize() +{ +#ifdef ADMISSIONS_CONTROL + atomic_init(&admissions_control_admitted, 0); + admissions_control_capacity = runtime_worker_threads_count * ADMISSIONS_CONTROL_GRANULARITY; +#endif +} + +static inline void +admissions_control_add(uint64_t admissions_estimate) +{ +#ifdef ADMISSIONS_CONTROL + assert(admissions_estimate > 0); + atomic_fetch_add(&admissions_control_admitted, admissions_estimate); + +#ifdef LOG_ADMISSIONS_CONTROL + debuglog("Runtime Admitted: %lu / %lu\n", admissions_control_admitted, admissions_control_capacity); +#endif + +#endif /* ADMISSIONS_CONTROL */ +} + +static inline void +admissions_control_substract(uint64_t admissions_estimate) +{ +#ifdef ADMISSIONS_CONTROL + /* Assumption: Should never underflow */ + if (unlikely(admissions_estimate > admissions_control_admitted)) panic("Admissions Estimate underflow\n"); + + atomic_fetch_sub(&admissions_control_admitted, admissions_estimate); + +#ifdef LOG_ADMISSIONS_CONTROL + debuglog("Runtime Admitted: %lu / %lu\n", admissions_control_admitted, admissions_control_capacity); +#endif + +#endif /* ADMISSIONS_CONTROL */ +} + + +static inline uint64_t +admissions_control_calculate_estimate(uint64_t estimated_execution, uint64_t relative_deadline) +{ +#ifdef ADMISSIONS_CONTROL + assert(relative_deadline != 0); + uint64_t admissions_estimate = (estimated_execution * (uint64_t)ADMISSIONS_CONTROL_GRANULARITY) + / relative_deadline; + if (admissions_estimate == 0) + panic("Ration of Deadline to Execution time cannot exceed %d\n", ADMISSIONS_CONTROL_GRANULARITY); + + return admissions_estimate; +#else + return 0; +#endif +} + +static inline uint64_t +admissions_control_calculate_estimate_us(uint32_t estimated_execution_us, uint32_t relative_deadline_us) +{ +#ifdef ADMISSIONS_CONTROL + assert(relative_deadline_us != 0); + return (uint64_t)((uint64_t)(estimated_execution_us * ADMISSIONS_CONTROL_GRANULARITY)) / relative_deadline_us; +#else + return 0; +#endif +} + +static inline void +admissions_control_log_decision(uint64_t admissions_estimate, bool admitted) +{ +#ifdef LOG_ADMISSIONS_CONTROL + debuglog("Admitted: %lu, Capacity: %lu, Estimate: %lu, Admitted? %s\n", admissions_control_admitted, + admissions_control_capacity, admissions_estimate, admitted ? "yes" : "no"); +#endif /* LOG_ADMISSIONS_CONTROL */ +} + +static inline uint64_t +admissions_control_decide(uint64_t admissions_estimate) +{ + uint64_t work_admitted = 1; /* Nominal non-zero value in case admissions control is disabled */ + +#ifdef ADMISSIONS_CONTROL + if (unlikely(admissions_estimate == 0)) panic("Admissions estimate should never be zero"); + + uint64_t total_admitted = atomic_load(&admissions_control_admitted); + + if (total_admitted + admissions_estimate >= admissions_control_capacity) { + admissions_control_log_decision(admissions_estimate, false); + work_admitted = 0; + } else { + admissions_control_log_decision(admissions_estimate, true); + admissions_control_add(admissions_estimate); + work_admitted = admissions_estimate; + } +#endif /* ADMISSIONS_CONTROL */ + + return work_admitted; +} diff --git a/runtime/include/admissions_info.h b/runtime/include/admissions_info.h new file mode 100644 index 0000000..591cffc --- /dev/null +++ b/runtime/include/admissions_info.h @@ -0,0 +1,55 @@ +#pragma once + +#include "perf_window.h" + +struct admissions_info { + struct perf_window perf_window; + int percentile; /* 50 - 99 */ + int control_index; /* Precomputed Lookup index when perf_window is full */ + uint64_t estimate; /* cycles */ + uint64_t relative_deadline; /* Relative deadline in cycles. This is duplicated state */ +}; + +/** + * Initializes perf window + * @param self + */ +static inline void +admissions_info_initialize(struct admissions_info *self, int percentile, uint64_t expected_execution, + uint64_t relative_deadline) +{ +#ifdef ADMISSIONS_CONTROL + + self->relative_deadline = relative_deadline; + self->estimate = admissions_control_calculate_estimate(expected_execution, relative_deadline); + 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; + + self->control_index = PERF_WINDOW_BUFFER_SIZE * percentile / 100; +#endif +} + +/* + * Adds an execution value to the perf window and calculates and caches and updated estimate + * @param self + * @param execution_duration + */ +static inline void +admissions_info_update(struct admissions_info *self, uint64_t execution_duration) +{ +#ifdef ADMISSIONS_CONTROL + assert(!software_interrupt_is_enabled()); + struct perf_window *perf_window = &self->perf_window; + + LOCK_LOCK(&self->perf_window.lock); + perf_window_add(perf_window, execution_duration); + 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 +} diff --git a/runtime/include/client_socket.h b/runtime/include/client_socket.h index 33f3276..a4c60fc 100644 --- a/runtime/include/client_socket.h +++ b/runtime/include/client_socket.h @@ -7,6 +7,7 @@ #include "panic.h" #include "debuglog.h" #include "http_response.h" +#include "http_total.h" #include "runtime.h" #include "worker_thread.h" @@ -32,14 +33,11 @@ client_socket_send(int client_socket, int status_code) switch (status_code) { case 503: response = HTTP_RESPONSE_503_SERVICE_UNAVAILABLE; - atomic_fetch_add(&runtime_total_5XX_responses, 1); + http_total_increment_5XX(); break; case 400: response = HTTP_RESPONSE_400_BAD_REQUEST; -#ifdef LOG_TOTAL_REQS_RESPS - atomic_fetch_add(&runtime_total_4XX_responses, 1); -#endif - + http_total_increment_4XX(); break; default: panic("%d is not a valid status code\n", status_code); diff --git a/runtime/include/debuglog.h b/runtime/include/debuglog.h index b557c8a..8ff46b6 100644 --- a/runtime/include/debuglog.h +++ b/runtime/include/debuglog.h @@ -1,6 +1,8 @@ #pragma once +#include #include +#include extern int32_t debuglog_file_descriptor; diff --git a/runtime/include/http_total.h b/runtime/include/http_total.h new file mode 100644 index 0000000..2f74cad --- /dev/null +++ b/runtime/include/http_total.h @@ -0,0 +1,57 @@ +#pragma once + +#include +#include + +/* + * Counts to track requests and responses + * requests and 5XX (admissions control rejections) are only tracked by the listener core, so they are not + * behind a compiler flag. 2XX and 4XX can be incremented by worker cores, so they are behind a flag because + * of concerns about contention + */ +extern _Atomic uint32_t http_total_requests; +extern _Atomic uint32_t http_total_5XX; + +#ifdef LOG_TOTAL_REQS_RESPS +extern _Atomic uint32_t http_total_2XX; +extern _Atomic uint32_t http_total_4XX; +#endif + +static inline void +http_total_init() +{ + atomic_init(&http_total_requests, 0); + atomic_init(&http_total_5XX, 0); +#ifdef LOG_TOTAL_REQS_RESPS + atomic_init(&http_total_2XX, 0); + atomic_init(&http_total_4XX, 0); +#endif +} + +static inline void +http_total_increment_request() +{ + atomic_fetch_add(&http_total_requests, 1); +} + +static inline void +http_total_increment_2xx() +{ +#ifdef LOG_TOTAL_REQS_RESPS + atomic_fetch_add(&http_total_2XX, 1); +#endif +} + +static inline void +http_total_increment_4XX() +{ +#ifdef LOG_TOTAL_REQS_RESPS + atomic_fetch_add(&http_total_4XX, 1); +#endif +} + +static inline void +http_total_increment_5XX() +{ + atomic_fetch_add(&http_total_5XX, 1); +} diff --git a/runtime/include/likely.h b/runtime/include/likely.h new file mode 100644 index 0000000..d41ced5 --- /dev/null +++ b/runtime/include/likely.h @@ -0,0 +1,4 @@ +#pragma once + +#define likely(x) __builtin_expect(!!(x), 1) +#define unlikely(x) __builtin_expect(!!(x), 0) diff --git a/runtime/include/module.h b/runtime/include/module.h index 71ae8cd..00afec6 100644 --- a/runtime/include/module.h +++ b/runtime/include/module.h @@ -5,9 +5,10 @@ #include #include +#include "admissions_control.h" +#include "admissions_info.h" #include "http.h" #include "panic.h" -#include "perf_window.h" #include "software_interrupt.h" #include "types.h" @@ -54,7 +55,7 @@ struct module { struct indirect_table_entry indirect_table[INDIRECT_TABLE_SIZE]; struct sockaddr_in socket_address; int socket_descriptor; - struct perf_window perf_window; + struct admissions_info admissions_info; int port; /* @@ -231,5 +232,6 @@ module_set_http_info(struct module *module, int request_count, char *request_hea void module_free(struct module *module); struct module *module_new(char *mod_name, char *mod_path, int32_t argument_count, uint32_t stack_sz, uint32_t max_heap, - uint32_t relative_deadline_us, int port, int req_sz, int resp_sz); + uint32_t relative_deadline_us, int port, int req_sz, int resp_sz, int admissions_percentile, + uint32_t expected_execution_us); int module_new_from_json(char *filename); diff --git a/runtime/include/perf_window.h b/runtime/include/perf_window.h index 0b7692e..a0dc2ff 100644 --- a/runtime/include/perf_window.h +++ b/runtime/include/perf_window.h @@ -21,7 +21,7 @@ * overwritten, providing a sorted circular buffer */ struct execution_node { - uint32_t execution_time; + uint64_t execution_time; uint16_t by_termination_idx; /* Reverse idx of the associated by_termination bin. Used for swaps! */ }; @@ -70,8 +70,8 @@ perf_window_swap(struct perf_window *self, uint16_t first_by_duration_idx, uint1 assert(self->by_termination[first_by_termination_idx] == first_by_duration_idx); assert(self->by_termination[second_by_termination_idx] == second_by_duration_idx); - uint32_t first_execution_time = self->by_duration[first_by_duration_idx].execution_time; - uint32_t second_execution_time = self->by_duration[second_by_duration_idx].execution_time; + uint64_t first_execution_time = self->by_duration[first_by_duration_idx].execution_time; + uint64_t second_execution_time = self->by_duration[second_by_duration_idx].execution_time; /* Swap Indices in Buffer*/ self->by_termination[first_by_termination_idx] = second_by_duration_idx; @@ -96,15 +96,15 @@ perf_window_swap(struct perf_window *self, uint16_t first_by_duration_idx, uint1 * @param value */ static inline void -perf_window_add(struct perf_window *self, uint32_t value) +perf_window_add(struct perf_window *self, uint64_t value) { assert(self != NULL); + if (unlikely(!LOCK_IS_LOCKED(&self->lock))) panic("lock not held when calling perf_window_add\n"); + /* A successful invocation should run for a non-zero amount of time */ assert(value > 0); - LOCK_LOCK(&self->lock); - /* If count is 0, then fill entire array with initial execution times */ if (self->count == 0) { for (int i = 0; i < PERF_WINDOW_BUFFER_SIZE; i++) { @@ -149,24 +149,27 @@ perf_window_add(struct perf_window *self, uint32_t value) self->count++; done: - LOCK_UNLOCK(&self->lock); + return; } /** * Returns pXX execution time * @param self + * @param percentile represented by double between 50 and 99 * @param percentile represented by double between 0 and 1 - * @returns execution time or -1 if by_termination is empty + * @returns execution time */ -static inline uint32_t -perf_window_get_percentile(struct perf_window *self, double percentile) +static inline uint64_t +perf_window_get_percentile(struct perf_window *self, int percentile, int precomputed_index) { assert(self != NULL); - assert(percentile > 0 && percentile < 1); + assert(percentile >= 50 && percentile <= 99); + int size = self->count; + assert(size > 0); - if (self->count == 0) return -1; + if (likely(size >= PERF_WINDOW_BUFFER_SIZE)) return self->by_duration[precomputed_index].execution_time; - return self->by_duration[(int)(PERF_WINDOW_BUFFER_SIZE * percentile)].execution_time; + return self->by_duration[size * percentile / 100].execution_time; } /** diff --git a/runtime/include/runtime.h b/runtime/include/runtime.h index 3f9391a..1fe1790 100644 --- a/runtime/include/runtime.h +++ b/runtime/include/runtime.h @@ -5,6 +5,7 @@ #include #include +#include "likely.h" #include "types.h" #define LISTENER_THREAD_CORE_ID 0 /* Dedicated Listener Core */ @@ -13,10 +14,6 @@ #define RUNTIME_LOG_FILE "awesome.log" #define RUNTIME_MAX_SANDBOX_REQUEST_COUNT (1 << 19) /* random! */ #define RUNTIME_READ_WRITE_VECTOR_LENGTH 16 -#define RUNTIME_GRANULARITY 100000 - -#define likely(x) __builtin_expect(!!(x), 1) -#define unlikely(x) __builtin_expect(!!(x), 0) /* * Descriptor of the epoll instance used to monitor the socket descriptors of registered @@ -36,43 +33,6 @@ extern float runtime_processor_speed_MHz; /* Count of worker threads and array of their pthread identifiers */ extern pthread_t runtime_worker_threads[]; extern uint32_t runtime_worker_threads_count; -extern uint64_t runtime_admissions_capacity; - -/* Listener Core Counts */ -extern _Atomic uint32_t runtime_total_requests; -extern _Atomic uint32_t runtime_total_sandbox_requests; -extern _Atomic uint32_t runtime_total_5XX_responses; - -#ifdef LOG_TOTAL_REQS_RESPS -/* Counts to track requests and responses */ -extern _Atomic uint32_t runtime_total_2XX_responses; -extern _Atomic uint32_t runtime_total_4XX_responses; -#endif - -#ifdef LOG_SANDBOX_TOTALS -/* Counts to track sanboxes running through state transitions */ -extern _Atomic uint32_t runtime_total_freed_requests; -extern _Atomic uint32_t runtime_total_initialized_sandboxes; -extern _Atomic uint32_t runtime_total_runnable_sandboxes; -extern _Atomic uint32_t runtime_total_blocked_sandboxes; -extern _Atomic uint32_t runtime_total_running_sandboxes; -extern _Atomic uint32_t runtime_total_preempted_sandboxes; -extern _Atomic uint32_t runtime_total_returned_sandboxes; -extern _Atomic uint32_t runtime_total_error_sandboxes; -extern _Atomic uint32_t runtime_total_complete_sandboxes; -#endif - -/* - * Unitless estimate of the instantaneous fraction of system capacity required to complete all previously - * admitted work. This is used to calculate free capacity as part of admissions control - * - * The estimated requirements of a single admitted request is calculated as - * estimated execution time (cycles) / relative deadline (cycles) - * - * These estimates are incremented on request acceptance and decremented on request completion (either - * success or failure) - */ -extern _Atomic uint64_t runtime_admitted; void alloc_linear_memory(void); void expand_memory(void); diff --git a/runtime/include/sandbox.h b/runtime/include/sandbox.h index c665050..c91ae90 100644 --- a/runtime/include/sandbox.h +++ b/runtime/include/sandbox.h @@ -12,6 +12,7 @@ #include "module.h" #include "ps_list.h" #include "sandbox_request.h" +#include "sandbox_state.h" #include "software_interrupt.h" #define SANDBOX_FILE_DESCRIPTOR_PREOPEN_MAGIC (707707707) /* upside down LOLLOLLOL 🤣😂🤣*/ @@ -26,29 +27,6 @@ struct sandbox_io_handle { int file_descriptor; }; -typedef enum -{ - SANDBOX_UNINITIALIZED = 0, /* Assumption: mmap zeros out structure */ - SANDBOX_ALLOCATED, - SANDBOX_SET_AS_INITIALIZED, - SANDBOX_INITIALIZED, - SANDBOX_SET_AS_RUNNABLE, - SANDBOX_RUNNABLE, - SANDBOX_SET_AS_RUNNING, - SANDBOX_RUNNING, - SANDBOX_SET_AS_PREEMPTED, - SANDBOX_PREEMPTED, - SANDBOX_SET_AS_BLOCKED, - SANDBOX_BLOCKED, - SANDBOX_SET_AS_RETURNED, - SANDBOX_RETURNED, - SANDBOX_SET_AS_COMPLETE, - SANDBOX_COMPLETE, - SANDBOX_SET_AS_ERROR, - SANDBOX_ERROR, - SANDBOX_STATE_COUNT -} sandbox_state_t; - struct sandbox { uint64_t id; sandbox_state_t state; @@ -71,12 +49,12 @@ struct sandbox { uint64_t last_state_change_timestamp; /* Used for bookkeeping of actual execution time */ /* Duration of time (in cycles) that the sandbox is in each state */ - uint32_t initializing_duration; - uint32_t runnable_duration; - uint32_t preempted_duration; - uint32_t running_duration; - uint32_t blocked_duration; - uint32_t returned_duration; + uint64_t initializing_duration; + uint64_t runnable_duration; + uint64_t preempted_duration; + uint64_t running_duration; + uint64_t blocked_duration; + uint64_t returned_duration; uint64_t absolute_deadline; uint64_t total_time; /* From Request to Response */ @@ -138,52 +116,6 @@ void sandbox_free_linear_memory(struct sandbox *sandbox); void sandbox_main(struct sandbox *sandbox); size_t sandbox_parse_http_request(struct sandbox *sandbox, size_t length); -static inline char * -sandbox_state_stringify(sandbox_state_t state) -{ - switch (state) { - case SANDBOX_UNINITIALIZED: - return "Uninitialized"; - case SANDBOX_ALLOCATED: - return "Allocated"; - case SANDBOX_SET_AS_INITIALIZED: - return "Set As Initialized"; - case SANDBOX_INITIALIZED: - return "Initialized"; - case SANDBOX_SET_AS_RUNNABLE: - return "Set As Runnable"; - case SANDBOX_RUNNABLE: - return "Runnable"; - case SANDBOX_SET_AS_RUNNING: - return "Set As Running"; - case SANDBOX_RUNNING: - return "Running"; - case SANDBOX_SET_AS_PREEMPTED: - return "Set As Preempted"; - case SANDBOX_PREEMPTED: - return "Preempted"; - case SANDBOX_SET_AS_BLOCKED: - return "Set As Blocked"; - case SANDBOX_BLOCKED: - return "Blocked"; - case SANDBOX_SET_AS_RETURNED: - return "Set As Returned"; - case SANDBOX_RETURNED: - return "Returned"; - case SANDBOX_SET_AS_COMPLETE: - return "Set As Complete"; - case SANDBOX_COMPLETE: - return "Complete"; - case SANDBOX_SET_AS_ERROR: - return "Set As Error"; - case SANDBOX_ERROR: - return "Error"; - default: - /* Crash, as this should be exclusive */ - panic("%d is an unrecognized sandbox state\n", state); - } -} - /** * Given a sandbox, returns the module that sandbox is executing @@ -295,12 +227,16 @@ sandbox_close_file_descriptor(struct sandbox *sandbox, int io_handle_index) } /** - * Prints key performance metrics for a sandbox to STDOUT + * Prints key performance metrics for a sandbox to runtime_sandbox_perf_log + * This is defined by an environment variable * @param sandbox */ static inline void sandbox_print_perf(struct sandbox *sandbox) { + /* If the log was not defined by an environment variable, early out */ + if (runtime_sandbox_perf_log == NULL) return; + uint32_t total_time_us = sandbox->total_time / runtime_processor_speed_MHz; uint32_t queued_us = (sandbox->allocation_timestamp - sandbox->request_arrival_timestamp) / runtime_processor_speed_MHz; diff --git a/runtime/include/sandbox_request.h b/runtime/include/sandbox_request.h index c6c4558..264bfa5 100644 --- a/runtime/include/sandbox_request.h +++ b/runtime/include/sandbox_request.h @@ -1,12 +1,16 @@ #pragma once +#include #include +#include #include #include "debuglog.h" #include "deque.h" +#include "http_total.h" #include "module.h" #include "runtime.h" +#include "sandbox_state.h" struct sandbox_request { uint64_t id; @@ -26,6 +30,30 @@ struct sandbox_request { DEQUE_PROTOTYPE(sandbox, struct sandbox_request *); +/* Count of the total number of requests we've ever allocated. Never decrements as it is used to generate IDs */ +extern _Atomic uint32_t sandbox_request_count; + +static inline void +sandbox_request_count_initialize() +{ + atomic_init(&sandbox_request_count, 0); +} + +static inline uint32_t +sandbox_request_count_postfix_increment() +{ + return atomic_fetch_add(&sandbox_request_count, 1); +} + +static inline void +sandbox_request_log_allocation(struct sandbox_request *sandbox_request) +{ +#ifdef LOG_REQUEST_ALLOCATION + debuglog("Sandbox Request %lu: of %s:%d\n", sandbox_request->id, sandbox_request->module->name, + sandbox_request->module->port); +#endif +} + /** * Allocates a new Sandbox Request and places it on the Global Deque * @param module the module we want to request @@ -44,8 +72,7 @@ sandbox_request_allocate(struct module *module, char *arguments, int socket_desc assert(sandbox_request); /* Sets the ID to the value before the increment */ - sandbox_request->id = atomic_fetch_add(&runtime_total_sandbox_requests, 1); - assert(runtime_total_sandbox_requests + runtime_total_5XX_responses <= runtime_total_requests); + sandbox_request->id = sandbox_request_count_postfix_increment(); sandbox_request->module = module; sandbox_request->arguments = arguments; @@ -53,11 +80,15 @@ sandbox_request_allocate(struct module *module, char *arguments, int socket_desc sandbox_request->socket_address = (struct sockaddr *)socket_address; sandbox_request->request_arrival_timestamp = request_arrival_timestamp; sandbox_request->absolute_deadline = request_arrival_timestamp + module->relative_deadline; - sandbox_request->admissions_estimate = admissions_estimate; -#ifdef LOG_REQUEST_ALLOCATION - debuglog("Sandbox Request %lu: of %s:%d\n", sandbox_request->id, sandbox_request->module->name, - sandbox_request->module->port); -#endif + /* + * Admissions Control State + * Assumption: an estimate of 0 should have been interpreted as a rejection + */ + assert(admissions_estimate != 0); + sandbox_request->admissions_estimate = admissions_estimate; + + sandbox_request_log_allocation(sandbox_request); + return sandbox_request; } diff --git a/runtime/include/sandbox_state.h b/runtime/include/sandbox_state.h new file mode 100644 index 0000000..26ee213 --- /dev/null +++ b/runtime/include/sandbox_state.h @@ -0,0 +1,80 @@ +#pragma once + +#include + +#include "likely.h" +#include "panic.h" + +typedef enum +{ + SANDBOX_UNINITIALIZED = 0, /* Assumption: mmap zeros out structure */ + SANDBOX_ALLOCATED, + SANDBOX_SET_AS_INITIALIZED, + SANDBOX_INITIALIZED, + SANDBOX_SET_AS_RUNNABLE, + SANDBOX_RUNNABLE, + SANDBOX_SET_AS_RUNNING, + SANDBOX_RUNNING, + SANDBOX_SET_AS_PREEMPTED, + SANDBOX_PREEMPTED, + SANDBOX_SET_AS_BLOCKED, + SANDBOX_BLOCKED, + SANDBOX_SET_AS_RETURNED, + SANDBOX_RETURNED, + SANDBOX_SET_AS_COMPLETE, + SANDBOX_COMPLETE, + SANDBOX_SET_AS_ERROR, + SANDBOX_ERROR, + SANDBOX_STATE_COUNT +} sandbox_state_t; + +extern const bool sandbox_state_is_terminal[SANDBOX_STATE_COUNT]; + +extern const char *sandbox_state_labels[SANDBOX_STATE_COUNT]; + +static inline const char * +sandbox_state_stringify(sandbox_state_t state) +{ + if (unlikely(state >= SANDBOX_STATE_COUNT)) panic("%d is an unrecognized sandbox state\n", state); + return sandbox_state_labels[state]; +} + + +static inline void +sandbox_state_log_transition(uint64_t sandbox_id, sandbox_state_t last_state, sandbox_state_t current_state) +{ +#ifdef LOG_STATE_CHANGES + debuglog("Sandbox %lu | %s => %s\n", sandbox_id, sandbox_state_stringify(last_state), + sandbox_state_stringify(current_state)); +#endif +} + +#ifdef LOG_SANDBOX_COUNT +extern _Atomic uint32_t sandbox_state_count[SANDBOX_STATE_COUNT]; +#endif + +static inline void +sandbox_count_initialize() +{ +#ifdef LOG_SANDBOX_COUNT + for (int i = 0; i < SANDBOX_STATE_COUNT; i++) atomic_init(&sandbox_state_count[i], 0); +#endif +} + +static inline void +runtime_sandbox_total_increment(sandbox_state_t state) +{ +#ifdef LOG_SANDBOX_COUNT + if (!sandbox_state_is_terminal[state]) panic("Unexpectedly logging intermediate transition state"); + atomic_fetch_add(&sandbox_state_count[state], 1); +#endif +} + +static inline void +runtime_sandbox_total_decrement(sandbox_state_t state) +{ +#ifdef LOG_SANDBOX_COUNT + if (atomic_load(&sandbox_state_count[state]) == 0) panic("Underflow of %s\n", sandbox_state_stringify(state)); + atomic_fetch_sub(&sandbox_state_count[state], 1); +#endif +} diff --git a/runtime/src/admissions_control.c b/runtime/src/admissions_control.c new file mode 100644 index 0000000..d5aba8b --- /dev/null +++ b/runtime/src/admissions_control.c @@ -0,0 +1,4 @@ +#include "admissions_control.h" + +_Atomic uint64_t admissions_control_admitted; +uint64_t admissions_control_capacity; diff --git a/runtime/src/http_total.c b/runtime/src/http_total.c new file mode 100644 index 0000000..6a3d3c8 --- /dev/null +++ b/runtime/src/http_total.c @@ -0,0 +1,34 @@ +#include + +#include "debuglog.h" +#include "http_total.h" + +/* 2XX + 4XX should equal sandboxes */ +/* Listener Core Bookkeeping */ +_Atomic uint32_t http_total_requests = 0; +_Atomic uint32_t http_total_5XX = 0; + +#ifdef LOG_TOTAL_REQS_RESPS +_Atomic uint32_t http_total_2XX = 0; +_Atomic uint32_t http_total_4XX = 0; +#endif + +void +http_total_log() +{ + uint32_t total_reqs = atomic_load(&http_total_requests); + uint32_t total_5XX = atomic_load(&http_total_5XX); + +#ifdef LOG_TOTAL_REQS_RESPS + uint32_t total_2XX = atomic_load(&http_total_2XX); + uint32_t total_4XX = atomic_load(&http_total_4XX); + + int64_t total_responses = total_2XX + total_4XX + total_5XX; + int64_t outstanding_requests = (int64_t)total_reqs - total_responses; + + debuglog("Requests: %u (%ld outstanding)\n\tResponses: %ld\n\t\t2XX: %u\n\t\t4XX: %u\n\t\t5XX: %u\n", + total_reqs, outstanding_requests, total_responses, total_2XX, total_4XX, total_5XX); +#else + debuglog("Requests: %u\n\tResponses:\n\t\t\t5XX: %u\n", total_reqs, total_5XX); +#endif +}; diff --git a/runtime/src/module.c b/runtime/src/module.c index 92c9c50..8e9f60f 100644 --- a/runtime/src/module.c +++ b/runtime/src/module.c @@ -1,3 +1,4 @@ +#include #include #include #include @@ -8,6 +9,7 @@ #include "debuglog.h" #include "http.h" +#include "likely.h" #include "module.h" #include "module_database.h" #include "panic.h" @@ -127,7 +129,8 @@ module_free(struct module *module) struct module * module_new(char *name, char *path, int32_t argument_count, uint32_t stack_size, uint32_t max_memory, - uint32_t relative_deadline_us, int port, int request_size, int response_size) + uint32_t relative_deadline_us, int port, int request_size, int response_size, int admissions_percentile, + uint32_t expected_execution_us) { int rc = 0; @@ -182,14 +185,22 @@ module_new(char *name, char *path, int32_t argument_count, uint32_t stack_size, strncpy(module->name, name, MODULE_MAX_NAME_LENGTH); strncpy(module->path, path, MODULE_MAX_PATH_LENGTH); - module->argument_count = argument_count; - module->stack_size = round_up_to_page(stack_size == 0 ? WASM_STACK_SIZE : stack_size); - module->max_memory = max_memory == 0 ? ((uint64_t)WASM_PAGE_SIZE * WASM_MAX_PAGES) : max_memory; + module->argument_count = argument_count; + module->stack_size = round_up_to_page(stack_size == 0 ? WASM_STACK_SIZE : stack_size); + module->max_memory = max_memory == 0 ? ((uint64_t)WASM_PAGE_SIZE * WASM_MAX_PAGES) : max_memory; + module->socket_descriptor = -1; + module->port = port; + + /* Deadlines */ module->relative_deadline_us = relative_deadline_us; module->relative_deadline = relative_deadline_us * runtime_processor_speed_MHz; - module->socket_descriptor = -1; - module->port = port; + /* Admissions Control */ + uint64_t expected_execution = expected_execution_us * runtime_processor_speed_MHz; + admissions_info_initialize(&module->admissions_info, admissions_percentile, expected_execution, + module->relative_deadline); + + /* Request Response Buffer */ if (request_size == 0) request_size = MODULE_DEFAULT_REQUEST_RESPONSE_SIZE; if (response_size == 0) response_size = MODULE_DEFAULT_REQUEST_RESPONSE_SIZE; module->max_request_size = request_size; @@ -218,9 +229,6 @@ module_new(char *name, char *path, int32_t argument_count, uint32_t stack_size, module_initialize_table(module); local_sandbox_context_cache.module_indirect_table = NULL; - /* Initialize Perf Window */ - perf_window_initialize(&module->perf_window); - /* Start listening for requests */ rc = module_listen(module); if (rc < 0) goto err_listen; @@ -350,6 +358,8 @@ module_new_from_json(char *file_name) int32_t argument_count = 0; uint32_t port = 0; uint32_t relative_deadline_us = 0; + uint32_t expected_execution_us = 0; + int admissions_percentile = 50; bool is_active = false; int32_t request_count = 0; int32_t response_count = 0; @@ -378,7 +388,24 @@ module_new_from_json(char *file_name) } else if (strcmp(key, "active") == 0) { is_active = (strcmp(val, "yes") == 0); } else if (strcmp(key, "relative-deadline-us") == 0) { - relative_deadline_us = atoi(val); + unsigned long long buffer = strtoull(val, NULL, 10); + if (buffer > UINT32_MAX) + panic("Max relative-deadline-us is %u, but entry was %llu\n", UINT32_MAX, + buffer); + relative_deadline_us = (uint32_t)buffer; + } else if (strcmp(key, "expected-execution-us") == 0) { + unsigned long long buffer = strtoull(val, NULL, 10); + if (buffer > UINT32_MAX) + panic("Max expected-execution-us is %u, but entry was %llu\n", UINT32_MAX, + buffer); + + expected_execution_us = (uint32_t)buffer; + } else if (strcmp(key, "admissions-percentile") == 0) { + unsigned long long buffer = strtoull(val, NULL, 10); + if (buffer > 99 || buffer < 50) + panic("admissions-percentile must be > 50 and <= 99 but was %llu\n", buffer); + + admissions_percentile = (int)buffer; } else if (strcmp(key, "http-req-headers") == 0) { assert(tokens[i + j + 1].type == JSMN_ARRAY); assert(tokens[i + j + 1].size <= HTTP_MAX_HEADER_COUNT); @@ -414,16 +441,24 @@ module_new_from_json(char *file_name) } else if (strcmp(key, "http-resp-content-type") == 0) { strcpy(response_content_type, val); } else { +#ifdef LOG_MODULE_LOADING debuglog("Invalid (%s,%s)\n", key, val); +#endif } j += ntks; } i += ntoks; +/* Validate presence of required fields */ +#ifdef ADMISSIONS_CONTROL + if (expected_execution_us == 0) panic("expected-execution-us is required for EDF\n"); +#endif + if (is_active) { /* Allocate a module based on the values from the JSON */ struct module *module = module_new(module_name, module_path, argument_count, 0, 0, - relative_deadline_us, port, request_size, response_size); + relative_deadline_us, port, request_size, response_size, + admissions_percentile, expected_execution_us); if (module == NULL) goto module_new_err; assert(module); diff --git a/runtime/src/runtime.c b/runtime/src/runtime.c index 5de9cb7..df218f8 100644 --- a/runtime/src/runtime.c +++ b/runtime/src/runtime.c @@ -2,6 +2,7 @@ #include #include +#include "admissions_control.h" #include "arch/context.h" #include "client_socket.h" #include "debuglog.h" @@ -18,72 +19,7 @@ * Shared Process State * **************************/ -int runtime_epoll_file_descriptor; -_Atomic uint64_t runtime_admitted; -uint64_t runtime_admissions_capacity; - -/* Listener Core Bookkeeping */ -_Atomic uint32_t runtime_total_requests = 0; - -/* Sandbox Requests + 5XX Responses (Rejections) should always equal total requests */ -_Atomic uint32_t runtime_total_sandbox_requests = 0; -_Atomic uint32_t runtime_total_5XX_responses = 0; - -#ifdef LOG_TOTAL_REQS_RESPS -/* 2XX + 4XX should equal sandboxes */ -_Atomic uint32_t runtime_total_2XX_responses = 0; -_Atomic uint32_t runtime_total_4XX_responses = 0; - -void -runtime_log_requests_responses() -{ - uint32_t total_reqs = atomic_load(&runtime_total_requests); - uint32_t total_2XX = atomic_load(&runtime_total_2XX_responses); - uint32_t total_4XX = atomic_load(&runtime_total_4XX_responses); - uint32_t total_5XX = atomic_load(&runtime_total_5XX_responses); - - int64_t total_responses = total_2XX + total_4XX + total_5XX; - int64_t outstanding_requests = (int64_t)total_reqs - total_responses; - - debuglog("Requests: %u (%ld outstanding)\n\tResponses: %ld\n\t\t2XX: %u\n\t\t4XX: %u\n\t\t5XX: %u\n", - total_reqs, outstanding_requests, total_responses, total_2XX, total_4XX, total_5XX); -}; -#endif - -#ifdef LOG_SANDBOX_TOTALS -_Atomic uint32_t runtime_total_freed_requests = 0; -_Atomic uint32_t runtime_total_initialized_sandboxes = 0; -_Atomic uint32_t runtime_total_runnable_sandboxes = 0; -_Atomic uint32_t runtime_total_blocked_sandboxes = 0; -_Atomic uint32_t runtime_total_running_sandboxes = 0; -_Atomic uint32_t runtime_total_preempted_sandboxes = 0; -_Atomic uint32_t runtime_total_returned_sandboxes = 0; -_Atomic uint32_t runtime_total_error_sandboxes = 0; -_Atomic uint32_t runtime_total_complete_sandboxes = 0; - -/* - * Function intended to be interactively run in a debugger to look at sandbox totals - * via `call runtime_log_sandbox_states()` - */ -void -runtime_log_sandbox_states() -{ - uint32_t total_initialized = atomic_load(&runtime_total_initialized_sandboxes); - uint32_t total_runnable = atomic_load(&runtime_total_runnable_sandboxes); - uint32_t total_blocked = atomic_load(&runtime_total_blocked_sandboxes); - uint32_t total_running = atomic_load(&runtime_total_running_sandboxes); - uint32_t total_preempted = atomic_load(&runtime_total_preempted_sandboxes); - uint32_t total_returned = atomic_load(&runtime_total_returned_sandboxes); - uint32_t total_error = atomic_load(&runtime_total_error_sandboxes); - uint32_t total_complete = atomic_load(&runtime_total_complete_sandboxes); - - - debuglog("Initialized: %u\n\tRunnable: %u\n\tBlocked: %u\n\tRunning: %u\n\tPreempted: %u\n\tReturned: " - "%u\n\tError: %u\n\tComplete: %u\n", - total_initialized, total_runnable, total_blocked, total_running, total_preempted, total_returned, - total_error, total_complete); -}; -#endif +int runtime_epoll_file_descriptor; /****************************************** * Shared Process / Listener Thread Logic * @@ -95,34 +31,15 @@ runtime_log_sandbox_states() void runtime_initialize(void) { - atomic_init(&runtime_total_requests, 0); - atomic_init(&runtime_total_sandbox_requests, 0); - atomic_init(&runtime_total_5XX_responses, 0); - -#ifdef LOG_TOTAL_REQS_RESPS - atomic_init(&runtime_total_2XX_responses, 0); - atomic_init(&runtime_total_4XX_responses, 0); -#endif -#ifdef LOG_SANDBOX_TOTALS - atomic_init(&runtime_total_freed_requests, 0); - atomic_init(&runtime_total_initialized_sandboxes, 0); - atomic_init(&runtime_total_runnable_sandboxes, 0); - atomic_init(&runtime_total_blocked_sandboxes, 0); - atomic_init(&runtime_total_running_sandboxes, 0); - atomic_init(&runtime_total_preempted_sandboxes, 0); - atomic_init(&runtime_total_returned_sandboxes, 0); - atomic_init(&runtime_total_error_sandboxes, 0); - atomic_init(&runtime_total_complete_sandboxes, 0); -#endif + http_total_init(); + sandbox_request_count_initialize(); + sandbox_count_initialize(); /* Setup epoll */ runtime_epoll_file_descriptor = epoll_create1(0); assert(runtime_epoll_file_descriptor >= 0); - /* Allocate and Initialize the global deque - TODO: Improve to expose variant as a config #Issue 93 - */ - + /* Setup Scheduler */ switch (runtime_scheduler) { case RUNTIME_SCHEDULER_EDF: global_request_scheduler_minheap_initialize(); @@ -139,12 +56,8 @@ runtime_initialize(void) software_interrupt_mask_signal(SIGALRM); signal(SIGPIPE, SIG_IGN); - /* Initialize http_parser_settings global */ http_parser_settings_initialize(); - - /* Initialize admissions control state */ - runtime_admissions_capacity = runtime_worker_threads_count * RUNTIME_GRANULARITY; - runtime_admitted = 0; + admissions_control_initialize(); } /************************* @@ -181,7 +94,6 @@ listener_thread_main(void *dummy) /* Assumption: Because epoll_wait is set to not timeout, we should always have descriptors here */ assert(descriptor_count > 0); - /* Capture Start Time to calculate absolute deadline */ uint64_t request_arrival_timestamp = __getcycles(); for (int i = 0; i < descriptor_count; i++) { /* Check Event to determine if epoll returned an error */ @@ -237,24 +149,18 @@ listener_thread_main(void *dummy) module->name); } - atomic_fetch_add(&runtime_total_requests, 1); - - /* Perform Admission Control */ + http_total_increment_request(); - uint32_t estimated_execution = perf_window_get_percentile(&module->perf_window, 0.5); /* - * If this is the first execution, assume a default execution - * TODO: Enhance module specification to provide "seed" value of estimated duration + * Perform admissions control. + * If 0, workload was rejected, so close with 503 and continue */ - if (estimated_execution == -1) estimated_execution = 1000; - - uint64_t admissions_estimate = (((uint64_t)estimated_execution) * RUNTIME_GRANULARITY) - / module->relative_deadline; - - if (runtime_admitted + admissions_estimate >= runtime_admissions_capacity) { + uint64_t work_admitted = admissions_control_decide(module->admissions_info.estimate); + if (work_admitted == 0) { client_socket_send(client_socket, 503); - if (close(client_socket) < 0) + if (unlikely(close(client_socket) < 0)) debuglog("Error closing client socket - %s", strerror(errno)); + continue; } @@ -262,18 +168,11 @@ listener_thread_main(void *dummy) struct sandbox_request *sandbox_request = sandbox_request_allocate(module, module->name, client_socket, (const struct sockaddr *)&client_address, - request_arrival_timestamp, admissions_estimate); + request_arrival_timestamp, work_admitted); /* Add to the Global Sandbox Request Scheduler */ global_request_scheduler_add(sandbox_request); - /* Add to work accepted by the runtime */ - runtime_admitted += admissions_estimate; - -#ifdef LOG_ADMISSIONS_CONTROL - debuglog("Runtime Admitted: %lu / %lu\n", runtime_admitted, - runtime_admissions_capacity); -#endif } /* while true */ } /* for loop */ } /* while true */ diff --git a/runtime/src/sandbox.c b/runtime/src/sandbox.c index 10b34f2..21bfab7 100644 --- a/runtime/src/sandbox.c +++ b/runtime/src/sandbox.c @@ -3,9 +3,11 @@ #include #include +#include "admissions_control.h" #include "current_sandbox.h" #include "debuglog.h" #include "http_parser_settings.h" +#include "http_total.h" #include "local_completion_queue.h" #include "local_runqueue.h" #include "panic.h" @@ -218,6 +220,9 @@ sandbox_build_and_send_client_response(struct sandbox *sandbox) sent += rc; } + + http_total_increment_2xx(); + return 0; } @@ -257,8 +262,8 @@ sandbox_initialize_io_handles_and_file_descriptors(struct sandbox *sandbox) /** * Sandbox execution logic - * Handles setup, request parsing, WebAssembly initialization, function execution, response building and sending, and - * cleanup + * Handles setup, request parsing, WebAssembly initialization, function execution, response building and + * sending, and cleanup */ void current_sandbox_main(void) @@ -306,9 +311,7 @@ current_sandbox_main(void) goto err; }; -#ifdef LOG_TOTAL_REQS_RESPS - atomic_fetch_add(&runtime_total_2XX_responses, 1); -#endif + http_total_increment_2xx(); sandbox->response_timestamp = __getcycles(); @@ -436,24 +439,15 @@ sandbox_set_as_initialized(struct sandbox *sandbox, struct sandbox_request *sand assert(!software_interrupt_is_enabled()); assert(sandbox != NULL); assert(sandbox->state == SANDBOX_ALLOCATED); - assert(sandbox_request != NULL); - assert(sandbox_request->arguments != NULL); - assert(sandbox_request->request_arrival_timestamp > 0); - assert(sandbox_request->socket_address != NULL); - assert(sandbox_request->socket_descriptor > 0); - assert(allocation_timestamp > 0); -#ifdef LOG_STATE_CHANGES - debuglog("Sandbox %lu | Uninitialized => Initialized\n", sandbox_request->request_arrival_timestamp); -#endif + sandbox->id = sandbox_request->id; sandbox->admissions_estimate = sandbox_request->admissions_estimate; - sandbox->request_arrival_timestamp = sandbox_request->request_arrival_timestamp; - sandbox->allocation_timestamp = allocation_timestamp; - sandbox->last_state_change_timestamp = allocation_timestamp; - sandbox->state = SANDBOX_SET_AS_INITIALIZED; + sandbox->request_arrival_timestamp = sandbox_request->request_arrival_timestamp; + sandbox->allocation_timestamp = allocation_timestamp; + sandbox->state = SANDBOX_SET_AS_INITIALIZED; /* Initialize the sandbox's context, stack, and instruction pointer */ arch_context_init(&sandbox->ctxt, (reg_t)current_sandbox_main, @@ -471,10 +465,12 @@ sandbox_set_as_initialized(struct sandbox *sandbox, struct sandbox_request *sand sandbox->client_socket_descriptor = sandbox_request->socket_descriptor; memcpy(&sandbox->client_address, sandbox_request->socket_address, sizeof(struct sockaddr)); - sandbox->state = SANDBOX_INITIALIZED; -#ifdef LOG_SANDBOX_TOTALS - atomic_fetch_add(&runtime_total_initialized_sandboxes, 1); -#endif + sandbox->last_state_change_timestamp = allocation_timestamp; /* We use arg to include alloc */ + sandbox->state = SANDBOX_INITIALIZED; + + /* State Change Bookkeeping */ + sandbox_state_log_transition(sandbox->id, SANDBOX_UNINITIALIZED, SANDBOX_INITIALIZED); + runtime_sandbox_total_increment(SANDBOX_INITIALIZED); } /** @@ -499,25 +495,13 @@ sandbox_set_as_runnable(struct sandbox *sandbox, sandbox_state_t last_state) sandbox->state = SANDBOX_SET_AS_RUNNABLE; -#ifdef LOG_STATE_CHANGES - debuglog("Sandbox %lu | %s => Runnable\n", sandbox->id, sandbox_state_stringify(last_state)); -#endif - switch (last_state) { case SANDBOX_INITIALIZED: { sandbox->initializing_duration += duration_of_last_state; -#ifdef LOG_SANDBOX_TOTALS - atomic_fetch_sub(&runtime_total_initialized_sandboxes, 1); - atomic_fetch_add(&runtime_total_runnable_sandboxes, 1); -#endif break; } case SANDBOX_BLOCKED: { sandbox->blocked_duration += duration_of_last_state; -#ifdef LOG_SANDBOX_TOTALS - atomic_fetch_sub(&runtime_total_blocked_sandboxes, 1); - atomic_fetch_add(&runtime_total_runnable_sandboxes, 1); -#endif break; } default: { @@ -529,6 +513,11 @@ sandbox_set_as_runnable(struct sandbox *sandbox, sandbox_state_t last_state) local_runqueue_add(sandbox); sandbox->last_state_change_timestamp = now; sandbox->state = SANDBOX_RUNNABLE; + + /* State Change Bookkeeping */ + sandbox_state_log_transition(sandbox->id, last_state, SANDBOX_RUNNABLE); + runtime_sandbox_total_increment(SANDBOX_RUNNABLE); + runtime_sandbox_total_decrement(last_state); } /** @@ -554,25 +543,14 @@ sandbox_set_as_running(struct sandbox *sandbox, sandbox_state_t last_state) uint32_t duration_of_last_state = now - sandbox->last_state_change_timestamp; sandbox->state = SANDBOX_SET_AS_RUNNING; -#ifdef LOG_STATE_CHANGES - debuglog("Sandbox %lu | %s => Running\n", sandbox->id, sandbox_state_stringify(last_state)); -#endif switch (last_state) { case SANDBOX_RUNNABLE: { sandbox->runnable_duration += duration_of_last_state; -#ifdef LOG_SANDBOX_TOTALS - atomic_fetch_sub(&runtime_total_runnable_sandboxes, 1); - atomic_fetch_add(&runtime_total_running_sandboxes, 1); -#endif break; } case SANDBOX_PREEMPTED: { sandbox->preempted_duration += duration_of_last_state; -#ifdef LOG_SANDBOX_TOTALS - atomic_fetch_sub(&runtime_total_preempted_sandboxes, 1); - atomic_fetch_add(&runtime_total_running_sandboxes, 1); -#endif break; } default: { @@ -584,6 +562,11 @@ sandbox_set_as_running(struct sandbox *sandbox, sandbox_state_t last_state) current_sandbox_set(sandbox); sandbox->last_state_change_timestamp = now; sandbox->state = SANDBOX_RUNNING; + + /* State Change Bookkeeping */ + sandbox_state_log_transition(sandbox->id, last_state, SANDBOX_RUNNING); + runtime_sandbox_total_increment(SANDBOX_RUNNING); + runtime_sandbox_total_decrement(last_state); } /** @@ -606,17 +589,10 @@ sandbox_set_as_preempted(struct sandbox *sandbox, sandbox_state_t last_state) uint32_t duration_of_last_state = now - sandbox->last_state_change_timestamp; sandbox->state = SANDBOX_SET_AS_PREEMPTED; -#ifdef LOG_STATE_CHANGES - debuglog("Sandbox %lu | %s => Preempted\n", sandbox->id, sandbox_state_stringify(last_state)); -#endif switch (last_state) { case SANDBOX_RUNNING: { sandbox->running_duration += duration_of_last_state; -#ifdef LOG_SANDBOX_TOTALS - atomic_fetch_sub(&runtime_total_running_sandboxes, 1); - atomic_fetch_add(&runtime_total_preempted_sandboxes, 1); -#endif break; } default: { @@ -627,6 +603,11 @@ sandbox_set_as_preempted(struct sandbox *sandbox, sandbox_state_t last_state) sandbox->last_state_change_timestamp = now; sandbox->state = SANDBOX_PREEMPTED; + + /* State Change Bookkeeping */ + sandbox_state_log_transition(sandbox->id, last_state, SANDBOX_PREEMPTED); + runtime_sandbox_total_increment(SANDBOX_PREEMPTED); + runtime_sandbox_total_decrement(SANDBOX_RUNNING); } /** @@ -647,18 +628,11 @@ sandbox_set_as_blocked(struct sandbox *sandbox, sandbox_state_t last_state) uint32_t duration_of_last_state = now - sandbox->last_state_change_timestamp; sandbox->state = SANDBOX_SET_AS_BLOCKED; -#ifdef LOG_STATE_CHANGES - debuglog("Sandbox %lu | %s => Blocked\n", sandbox->id, sandbox_state_stringify(last_state)); -#endif switch (last_state) { case SANDBOX_RUNNING: { sandbox->running_duration += duration_of_last_state; local_runqueue_delete(sandbox); -#ifdef LOG_SANDBOX_TOTALS - atomic_fetch_sub(&runtime_total_running_sandboxes, 1); - atomic_fetch_add(&runtime_total_blocked_sandboxes, 1); -#endif break; } default: { @@ -669,6 +643,11 @@ sandbox_set_as_blocked(struct sandbox *sandbox, sandbox_state_t last_state) sandbox->last_state_change_timestamp = now; sandbox->state = SANDBOX_BLOCKED; + + /* State Change Bookkeeping */ + sandbox_state_log_transition(sandbox->id, last_state, SANDBOX_BLOCKED); + runtime_sandbox_total_increment(SANDBOX_BLOCKED); + runtime_sandbox_total_decrement(last_state); } /** @@ -690,9 +669,6 @@ sandbox_set_as_returned(struct sandbox *sandbox, sandbox_state_t last_state) uint32_t duration_of_last_state = now - sandbox->last_state_change_timestamp; sandbox->state = SANDBOX_SET_AS_RETURNED; -#ifdef LOG_STATE_CHANGES - debuglog("Sandbox %lu | %s => Returned\n", sandbox->id, sandbox_state_stringify(last_state)); -#endif switch (last_state) { case SANDBOX_RUNNING: { @@ -701,10 +677,6 @@ sandbox_set_as_returned(struct sandbox *sandbox, sandbox_state_t last_state) sandbox->running_duration += duration_of_last_state; local_runqueue_delete(sandbox); sandbox_free_linear_memory(sandbox); -#ifdef LOG_SANDBOX_TOTALS - atomic_fetch_sub(&runtime_total_running_sandboxes, 1); - atomic_fetch_add(&runtime_total_returned_sandboxes, 1); -#endif break; } default: { @@ -715,6 +687,11 @@ sandbox_set_as_returned(struct sandbox *sandbox, sandbox_state_t last_state) sandbox->last_state_change_timestamp = now; sandbox->state = SANDBOX_RETURNED; + + /* State Change Bookkeeping */ + sandbox_state_log_transition(sandbox->id, last_state, SANDBOX_RETURNED); + runtime_sandbox_total_increment(SANDBOX_RETURNED); + runtime_sandbox_total_decrement(last_state); } /** @@ -733,31 +710,21 @@ void sandbox_set_as_error(struct sandbox *sandbox, sandbox_state_t last_state) { assert(sandbox); + assert(!software_interrupt_is_enabled()); uint64_t now = __getcycles(); uint32_t duration_of_last_state = now - sandbox->last_state_change_timestamp; sandbox->state = SANDBOX_SET_AS_ERROR; -#ifdef LOG_STATE_CHANGES - debuglog("Sandbox %lu | %s => Error\n", sandbox->id, sandbox_state_stringify(last_state)); -#endif switch (last_state) { case SANDBOX_SET_AS_INITIALIZED: /* Technically, this is a degenerate sandbox that we generate by hand */ sandbox->initializing_duration += duration_of_last_state; -#ifdef LOG_SANDBOX_TOTALS - atomic_fetch_sub(&runtime_total_initialized_sandboxes, 1); - atomic_fetch_add(&runtime_total_error_sandboxes, 1); -#endif break; case SANDBOX_RUNNING: { sandbox->running_duration += duration_of_last_state; local_runqueue_delete(sandbox); -#ifdef LOG_SANDBOX_TOTALS - atomic_fetch_sub(&runtime_total_running_sandboxes, 1); - atomic_fetch_add(&runtime_total_error_sandboxes, 1); -#endif break; } default: { @@ -766,24 +733,18 @@ sandbox_set_as_error(struct sandbox *sandbox, sandbox_state_t last_state) } } + uint64_t sandbox_id = sandbox->id; + sandbox->state = SANDBOX_ERROR; + sandbox_print_perf(sandbox); sandbox_free_linear_memory(sandbox); - - sandbox->last_state_change_timestamp = now; - sandbox->state = SANDBOX_ERROR; - - if (runtime_sandbox_perf_log != NULL) sandbox_print_perf(sandbox); - - /* Assumption: Should never underflow */ - assert(runtime_admitted >= sandbox->admissions_estimate); - - runtime_admitted -= sandbox->admissions_estimate; - -#ifdef LOG_ADMISSIONS_CONTROL - debuglog("Runtime Admitted: %lu / %lu\n", runtime_admitted, runtime_admissions_capacity); -#endif - - /* Do not touch sandbox state after adding to the completion queue to avoid use-after-free bugs */ + admissions_control_substract(sandbox->admissions_estimate); + /* Do not touch sandbox after adding to completion queue to avoid use-after-free bugs */ local_completion_queue_add(sandbox); + + /* State Change Bookkeeping */ + sandbox_state_log_transition(sandbox_id, last_state, SANDBOX_ERROR); + runtime_sandbox_total_increment(SANDBOX_ERROR); + runtime_sandbox_total_decrement(last_state); } /** @@ -797,22 +758,17 @@ void sandbox_set_as_complete(struct sandbox *sandbox, sandbox_state_t last_state) { assert(sandbox); + assert(!software_interrupt_is_enabled()); + uint64_t now = __getcycles(); uint32_t duration_of_last_state = now - sandbox->last_state_change_timestamp; sandbox->state = SANDBOX_SET_AS_COMPLETE; -#ifdef LOG_STATE_CHANGES - debuglog("Sandbox %lu | %s => Complete\n", sandbox->id, sandbox_state_stringify(last_state)); -#endif switch (last_state) { case SANDBOX_RETURNED: { sandbox->completion_timestamp = now; sandbox->returned_duration += duration_of_last_state; -#ifdef LOG_SANDBOX_TOTALS - atomic_fetch_sub(&runtime_total_returned_sandboxes, 1); - atomic_fetch_add(&runtime_total_complete_sandboxes, 1); -#endif break; } default: { @@ -821,27 +777,19 @@ sandbox_set_as_complete(struct sandbox *sandbox, sandbox_state_t last_state) } } - sandbox->last_state_change_timestamp = now; - sandbox->state = SANDBOX_COMPLETE; - - /* - * TODO: Enhance to include "spinning" or better "local|global scheduling latency" as well. - */ - perf_window_add(&sandbox->module->perf_window, sandbox->running_duration); - - /* Assumption: Should never underflow */ - assert(runtime_admitted >= sandbox->admissions_estimate); - - runtime_admitted -= sandbox->admissions_estimate; - -#ifdef LOG_ADMISSIONS_CONTROL - debuglog("Runtime Admitted: %lu / %lu\n", runtime_admitted, runtime_admissions_capacity); -#endif - - if (runtime_sandbox_perf_log != NULL) sandbox_print_perf(sandbox); - - /* Do not touch sandbox state after adding to the completion queue to avoid use-after-free bugs */ + uint64_t sandbox_id = sandbox->id; + sandbox->state = SANDBOX_COMPLETE; + sandbox_print_perf(sandbox); + /* Admissions Control Post Processing */ + admissions_info_update(&sandbox->module->admissions_info, sandbox->running_duration); + admissions_control_substract(sandbox->admissions_estimate); + /* Do not touch sandbox state after adding to completion queue to avoid use-after-free bugs */ local_completion_queue_add(sandbox); + + /* State Change Bookkeeping */ + sandbox_state_log_transition(sandbox_id, last_state, SANDBOX_COMPLETE); + runtime_sandbox_total_increment(SANDBOX_COMPLETE); + runtime_sandbox_total_decrement(last_state); } /** @@ -881,9 +829,6 @@ sandbox_allocate(struct sandbox_request *sandbox_request) /* Set state to initializing */ sandbox_set_as_initialized(sandbox, sandbox_request, now); -#ifdef LOG_SANDBOX_TOTALS - atomic_fetch_add(&runtime_total_freed_requests, 1); -#endif free(sandbox_request); done: return sandbox; diff --git a/runtime/src/sandbox_request.c b/runtime/src/sandbox_request.c new file mode 100644 index 0000000..f19f7f4 --- /dev/null +++ b/runtime/src/sandbox_request.c @@ -0,0 +1,3 @@ +#include "sandbox_request.h" + +_Atomic uint32_t sandbox_request_count = 0; diff --git a/runtime/src/sandbox_state.c b/runtime/src/sandbox_state.c new file mode 100644 index 0000000..011340c --- /dev/null +++ b/runtime/src/sandbox_state.c @@ -0,0 +1,72 @@ +#include +#include +#include +#include +#include + +#include "debuglog.h" +#include "sandbox_state.h" + +const bool sandbox_state_is_terminal[SANDBOX_STATE_COUNT] = { + + [SANDBOX_UNINITIALIZED] = false, [SANDBOX_ALLOCATED] = false, + [SANDBOX_INITIALIZED] = true, [SANDBOX_SET_AS_RUNNABLE] = false, + [SANDBOX_RUNNABLE] = true, [SANDBOX_SET_AS_RUNNING] = false, + [SANDBOX_RUNNING] = true, [SANDBOX_SET_AS_PREEMPTED] = false, + [SANDBOX_PREEMPTED] = true, [SANDBOX_SET_AS_BLOCKED] = false, + [SANDBOX_BLOCKED] = true, [SANDBOX_SET_AS_RETURNED] = false, + [SANDBOX_RETURNED] = true, [SANDBOX_SET_AS_COMPLETE] = false, + [SANDBOX_COMPLETE] = true, [SANDBOX_SET_AS_ERROR] = false, + [SANDBOX_ERROR] = true +}; + +const char *sandbox_state_labels[SANDBOX_STATE_COUNT] = { + + [SANDBOX_UNINITIALIZED] = "Uninitialized", + [SANDBOX_ALLOCATED] = "Allocated", + [SANDBOX_SET_AS_INITIALIZED] = "Transitioning to Initialized", + [SANDBOX_INITIALIZED] = "Initialized", + [SANDBOX_SET_AS_RUNNABLE] = "Transitioning to Runnable", + [SANDBOX_RUNNABLE] = "Runnable", + [SANDBOX_SET_AS_RUNNING] = "Transitioning to Running", + [SANDBOX_RUNNING] = "Running", + [SANDBOX_SET_AS_PREEMPTED] = "Transitioning to Preempted", + [SANDBOX_PREEMPTED] = "Preempted", + [SANDBOX_SET_AS_BLOCKED] = "Transitioning to Blocked", + [SANDBOX_BLOCKED] = "Blocked", + [SANDBOX_SET_AS_RETURNED] = "Transitioning to Returned", + [SANDBOX_RETURNED] = "Returned", + [SANDBOX_SET_AS_COMPLETE] = "Transitioning to Complete", + [SANDBOX_COMPLETE] = "Complete", + [SANDBOX_SET_AS_ERROR] = "Transitioning to Error", + [SANDBOX_ERROR] = "Error" +}; + +#ifdef LOG_SANDBOX_COUNT +_Atomic uint32_t sandbox_state_count[SANDBOX_STATE_COUNT]; +#endif + +/* + * Function intended to be interactively run in a debugger to look at sandbox totals + * via `call runtime_log_sandbox_states()` + */ +void +runtime_log_sandbox_states() +{ +#ifdef LOG_SANDBOX_COUNT + const size_t buffer_size = 1000; + char buffer[buffer_size] = ""; + for (int i = 0; i < SANDBOX_STATE_COUNT; i++) { + const size_t tiny_buffer_size = 50; + char tiny_buffer[tiny_buffer_size] = ""; + snprintf(tiny_buffer, tiny_buffer_size - 1, "%s: %u\n\t", sandbox_state_stringify(i), + atomic_load(&sandbox_state_count[i])); + strncat(buffer, tiny_buffer, buffer_size - 1 - strlen(buffer)); + } + + debuglog("%s", buffer); + +#else + debuglog("Must compile with LOG_SANDBOX_COUNT for this functionality!\n"); +#endif +};