feat: Refactor of conditional compilation units

runtime/include/admissions_control.h

@@ -0,0 +1,123 @@
+#pragma once
+
+#include <stdatomic.h>
+#include <stdbool.h>
+#include <stdint.h>
+#include <unistd.h>
+
+#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;
+}

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
+}

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);

runtime/include/debuglog.h

@@ -1,6 +1,8 @@
 #pragma once
 
+#include <pthread.h>
 #include <stdint.h>
+#include <stdio.h>
 
 extern int32_t debuglog_file_descriptor;
 

runtime/include/http_total.h

@@ -0,0 +1,57 @@
+#pragma once
+
+#include <stdatomic.h>
+#include <stdint.h>
+
+/*
+ * 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);
+}

runtime/include/likely.h

@@ -0,0 +1,4 @@
+#pragma once
+
+#define likely(x)   __builtin_expect(!!(x), 1)
+#define unlikely(x) __builtin_expect(!!(x), 0)

runtime/include/module.h

@@ -5,9 +5,10 @@
 #include <sys/types.h>
 #include <netdb.h>
 
+#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);

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;
 }
 
 /**

runtime/include/runtime.h

@@ -5,6 +5,7 @@
 #include <stdatomic.h>
 #include <stdbool.h>
 
+#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);

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;

runtime/include/sandbox_request.h

@@ -1,12 +1,16 @@
 #pragma once
 
+#include <stdatomic.h>
 #include <stdbool.h>
+#include <stdint.h>
 #include <sys/socket.h>
 
 #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;
 }

runtime/include/sandbox_state.h

@@ -0,0 +1,80 @@
+#pragma once
+
+#include <stdatomic.h>
+
+#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
+}

runtime/src/admissions_control.c

@@ -0,0 +1,4 @@
+#include "admissions_control.h"
+
+_Atomic uint64_t admissions_control_admitted;
+uint64_t         admissions_control_capacity;

runtime/src/http_total.c

@@ -0,0 +1,34 @@
+#include <stdint.h>
+
+#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
+};

runtime/src/module.c

@@ -1,3 +1,4 @@
+#include <assert.h>
 #include <dlfcn.h>
 #include <jsmn.h>
 #include <stdio.h>
@@ -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);

runtime/src/runtime.c

@@ -2,6 +2,7 @@
 #include <sched.h>
 #include <sys/mman.h>
 
+#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 */

runtime/src/sandbox.c

@@ -3,9 +3,11 @@
 #include <signal.h>
 #include <sys/mman.h>
 
+#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;

runtime/src/sandbox_request.c

@@ -0,0 +1,3 @@
+#include "sandbox_request.h"
+
+_Atomic uint32_t sandbox_request_count = 0;

runtime/src/sandbox_state.c

@@ -0,0 +1,72 @@
+#include <stdatomic.h>
+#include <stdbool.h>
+#include <stdint.h>
+#include <stdio.h>
+#include <string.h>
+
+#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
+};