feat: signal tracking and pretty printing

.vscode/settings.json

@@ -99,7 +99,8 @@
 		"sandbox_state_history.h": "c",
 		"sandbox_set_as_running_user.h": "c",
 		"scheduler.h": "c",
-		"sandbox_set_as_returned.h": "c"
+		"sandbox_set_as_returned.h": "c",
+		"software_interrupt_counts.h": "c"
 	},
 	"files.exclude": {
 		"**/.git": true,

runtime/Makefile

@@ -49,21 +49,21 @@ BINARY_NAME=sledgert
 # CFLAGS += -DLOG_TO_FILE
 
 # Various Informational Logs for Debugging
+# CFLAGS += -DLOG_ADMISSIONS_CONTROL
+# CFLAGS += -DLOG_CONTEXT_SWITCHES
 # CFLAGS += -DLOG_HTTP_PARSER
 # CFLAGS += -DLOG_LOCK_OVERHEAD
-# CFLAGS += -DLOG_CONTEXT_SWITCHES
-# CFLAGS += -DLOG_ADMISSIONS_CONTROL
-# CFLAGS += -DLOG_REQUEST_ALLOCATION
-# CFLAGS += -DLOG_PREEMPTION
 # CFLAGS += -DLOG_MODULE_LOADING
+# CFLAGS += -DLOG_PREEMPTION
+# CFLAGS += -DLOG_REQUEST_ALLOCATION
+
+# Stores and logs extended signal information for each worker
+# CFLAGS += -DLOG_SOFTWARE_INTERRUPT_COUNTS
 
 # This adds an array of sandbox states to all sandbox structs and appends states at each transition
 # The history trucates when the number of elements equal SANDBOX_STATE_HISTORY_CAPACITY 
 # CFLAGS += -DLOG_STATE_CHANGES
 
-# Stores the max number of deferred SIGALRMS for each worker
-# CFLAGS += -DLOG_DEFERRED_SIGALRM_MAX
-
 # This dumps per module *.csv files containing the cycle a sandbox has been in RUNNING when each
 # page is allocated. This helps understand the relationship to memory allocation and execution time.
 # CFLAGS += -DLOG_SANDBOX_MEMORY_PROFILE
@@ -119,7 +119,7 @@ all: runtime
 bin/sledgert: ${CFILES}
 	@echo "Compiling runtime"
 	@mkdir -p bin/
-	${CC} ${INCLUDES} ${CFLAGS} ${LDFLAGS} ${JSMNCFLAGS} -L/usr/lib/ $^ -o bin/sledgert
+	${CC} ${CFLAGS} ${LDFLAGS} ${JSMNCFLAGS} ${INCLUDES}  -L/usr/lib/ $^ -o bin/sledgert
 
 .PHONY: runtime
 runtime: thirdparty bin/sledgert

runtime/include/pretty_print.h

@@ -0,0 +1,41 @@
+#pragma once
+
+#include <stdio.h>
+#include <stdarg.h>
+
+#define PRETTY_PRINT_COLOR_CODE_RED   "\033[1;31m"
+#define PRETTY_COLOR_CODE_GREEN       "\033[0;32m"
+#define PRETTY_PRINT_COLOR_CODE_RESET "\033[0m"
+#define PRETTY_PRINT_GREEN_ENABLED    PRETTY_COLOR_CODE_GREEN "Enabled" PRETTY_PRINT_COLOR_CODE_RESET
+#define PRETTY_PRINT_RED_DISABLED     PRETTY_PRINT_COLOR_CODE_RED "Disabled" PRETTY_PRINT_COLOR_CODE_RESET
+#define PRETTY_PRINT_KEY_LEN          30
+
+
+static inline void
+pretty_print_key(char *heading)
+{
+	printf("\t%-*s", PRETTY_PRINT_KEY_LEN, heading);
+}
+
+static inline void
+pretty_print_key_value(char *key, char *fmt, ...)
+{
+	va_list ap;
+	pretty_print_key(key);
+
+	va_start(ap, fmt);
+	vprintf(fmt, ap);
+	va_end(ap);
+}
+
+static inline void
+pretty_print_key_enabled(char *key)
+{
+	pretty_print_key_value(key, "%s\n", PRETTY_PRINT_GREEN_ENABLED);
+}
+
+static inline void
+pretty_print_key_disabled(char *key)
+{
+	pretty_print_key_value(key, "%s\n", PRETTY_PRINT_RED_DISABLED);
+}

runtime/include/sandbox_perf_log.h

@@ -1,5 +1,6 @@
 #pragma once
 
+#include "pretty_print.h"
 #include "runtime.h"
 #include "sandbox_types.h"
 
@@ -51,12 +52,12 @@ sandbox_perf_log_init()
 {
 	char *sandbox_perf_log_path = getenv("SLEDGE_SANDBOX_PERF_LOG");
 	if (sandbox_perf_log_path != NULL) {
-		printf("\tSandbox Performance Log: %s\n", sandbox_perf_log_path);
+		pretty_print_key_value("Sandbox Performance Log", "%s\n", sandbox_perf_log_path);
 		sandbox_perf_log = fopen(sandbox_perf_log_path, "w");
 		if (sandbox_perf_log == NULL) perror("sandbox_perf_log_init\n");
 		sandbox_perf_log_print_header();
 	} else {
-		printf("\tSandbox Performance Log: Disabled\n");
+		pretty_print_key_disabled("Sandbox Performance Log");
 	}
 }
 

runtime/include/sandbox_set_as_running_user.h

@@ -46,7 +46,7 @@ sandbox_set_as_running_user(struct sandbox *sandbox, sandbox_state_t last_state)
 	sandbox->state = SANDBOX_RUNNING_USER;
 
 	/* Now that we are preemptable, we can replay deferred sigalrms */
-	if (software_interrupt_deferred_sigalrm > 0) raise(SIGALRM);
+	software_interrupt_deferred_sigalrm_replay();
 }
 
 static inline void

runtime/include/scheduler.h

@@ -100,14 +100,6 @@ err:
 static inline struct sandbox *
 scheduler_get_next()
 {
-#ifdef LOG_DEFERRED_SIGALRM_MAX
-	if (unlikely(software_interrupt_deferred_sigalrm
-	             > software_interrupt_deferred_sigalrm_max[worker_thread_idx])) {
-		software_interrupt_deferred_sigalrm_max[worker_thread_idx] = software_interrupt_deferred_sigalrm;
-	}
-#endif
-
-	atomic_store(&software_interrupt_deferred_sigalrm, 0);
 	switch (scheduler) {
 	case SCHEDULER_EDF:
 		return scheduler_edf_get_next();
@@ -215,6 +207,8 @@ scheduler_preemptive_sched(ucontext_t *interrupted_context)
 {
 	assert(interrupted_context != NULL);
 
+	software_interrupt_deferred_sigalrm_clear();
+
 	/* Process epoll to make sure that all runnable jobs are considered for execution */
 	scheduler_execute_epoll_loop();
 
@@ -292,6 +286,8 @@ scheduler_cooperative_sched()
 	/* Assumption: only called by the "base context" */
 	assert(current_sandbox_get() == NULL);
 
+	software_interrupt_deferred_sigalrm_clear();
+
 	/* Try to wakeup sleeping sandboxes */
 	scheduler_execute_epoll_loop();
 

runtime/include/software_interrupt.h

@@ -5,6 +5,7 @@
 #include <panic.h>
 #include <pthread.h>
 #include <signal.h>
+#include <stdatomic.h>
 #include <stdbool.h>
 #include <stdio.h>
 #include <stdlib.h>
@@ -12,15 +13,9 @@
 
 #include "debuglog.h"
 #include "runtime.h"
+#include "software_interrupt_counts.h"
 #include "worker_thread.h"
 
-/************
- * Externs  *
- ***********/
-
-extern _Atomic thread_local volatile sig_atomic_t software_interrupt_deferred_sigalrm;
-extern _Atomic volatile sig_atomic_t *            software_interrupt_deferred_sigalrm_max;
-
 /*************************
  * Public Static Inlines *
  ************************/
@@ -74,13 +69,29 @@ software_interrupt_unmask_signal(int signal)
 	return 0;
 }
 
+extern thread_local _Atomic volatile sig_atomic_t deferred_sigalrm;
+
+static inline void
+software_interrupt_deferred_sigalrm_replay()
+{
+	if (deferred_sigalrm > 0) {
+		software_interrupt_counts_deferred_sigalrm_replay_increment();
+		raise(SIGALRM);
+	}
+}
+
+static inline void
+software_interrupt_deferred_sigalrm_clear()
+{
+	software_interrupt_counts_deferred_sigalrm_max_update(deferred_sigalrm);
+	atomic_store(&deferred_sigalrm, 0);
+}
+
 /*************************
- * Exports from module.c *
+ * Exports from software_interrupt.c *
  ************************/
 
-void software_interrupt_initialize(void);
 void software_interrupt_arm_timer(void);
+void software_interrupt_cleanup(void);
 void software_interrupt_disarm_timer(void);
-void software_interrupt_set_interval_duration(uint64_t cycles);
-void software_interrupt_deferred_sigalrm_max_free(void);
-void software_interrupt_deferred_sigalrm_max_print(void);
+void software_interrupt_initialize(void);

runtime/include/software_interrupt_counts.h

@@ -0,0 +1,80 @@
+#pragma once
+
+#include <stdatomic.h>
+#include <signal.h>
+#include <stdlib.h>
+
+#include "worker_thread.h"
+
+extern _Atomic volatile sig_atomic_t *software_interrupt_counts_deferred_sigalrm_max;
+extern _Atomic volatile sig_atomic_t *software_interrupt_counts_deferred_sigalrm_replay;
+extern _Atomic volatile sig_atomic_t *software_interrupt_counts_sigalrm_kernel;
+extern _Atomic volatile sig_atomic_t *software_interrupt_counts_sigalrm_thread;
+extern _Atomic volatile sig_atomic_t *software_interrupt_counts_sigusr;
+
+static inline void
+software_interrupt_counts_alloc()
+{
+#ifdef LOG_SOFTWARE_INTERRUPT_COUNTS
+	software_interrupt_counts_deferred_sigalrm_max    = calloc(runtime_worker_threads_count, sizeof(sig_atomic_t));
+	software_interrupt_counts_deferred_sigalrm_replay = calloc(runtime_worker_threads_count, sizeof(sig_atomic_t));
+	software_interrupt_counts_sigalrm_kernel          = calloc(runtime_worker_threads_count, sizeof(sig_atomic_t));
+	software_interrupt_counts_sigalrm_thread          = calloc(runtime_worker_threads_count, sizeof(sig_atomic_t));
+	software_interrupt_counts_sigusr                  = calloc(runtime_worker_threads_count, sizeof(sig_atomic_t));
+#endif
+}
+
+static inline void
+software_interrupt_counts_free()
+{
+#ifdef LOG_SOFTWARE_INTERRUPT_COUNTS
+	free((void *)software_interrupt_counts_deferred_sigalrm_max);
+	free((void *)software_interrupt_counts_sigalrm_kernel);
+	free((void *)software_interrupt_counts_sigalrm_thread);
+	free((void *)software_interrupt_counts_sigusr);
+#endif
+}
+
+static inline void
+software_interrupt_counts_deferred_sigalrm_max_update(int deferred_sigalrm_count)
+{
+#ifdef LOG_SOFTWARE_INTERRUPT_COUNTS
+	if (unlikely(deferred_sigalrm_count > software_interrupt_counts_deferred_sigalrm_max[worker_thread_idx])) {
+		software_interrupt_counts_deferred_sigalrm_max[worker_thread_idx] = deferred_sigalrm_count;
+	}
+#endif
+}
+
+static inline void
+software_interrupt_counts_deferred_sigalrm_replay_increment()
+{
+#ifdef LOG_SOFTWARE_INTERRUPT_COUNTS
+	atomic_fetch_add(&software_interrupt_counts_deferred_sigalrm_replay[worker_thread_idx], 1);
+#endif
+}
+
+static inline void
+software_interrupt_counts_sigalrm_kernel_increment()
+{
+#ifdef LOG_SOFTWARE_INTERRUPT_COUNTS
+	atomic_fetch_add(&software_interrupt_counts_sigalrm_kernel[worker_thread_idx], 1);
+#endif
+}
+
+static inline void
+software_interrupt_counts_sigalrm_thread_increment()
+{
+#ifdef LOG_SOFTWARE_INTERRUPT_COUNTS
+	atomic_fetch_add(&software_interrupt_counts_sigalrm_thread[worker_thread_idx], 1);
+#endif
+}
+
+static inline void
+software_interrupt_counts_sigusr_increment()
+{
+#ifdef LOG_SOFTWARE_INTERRUPT_COUNTS
+	atomic_fetch_add(&software_interrupt_counts_sigusr[worker_thread_idx], 1);
+#endif
+}
+
+extern void software_interrupt_counts_log();

runtime/src/main.c

@@ -14,6 +14,7 @@
 #include <sys/fcntl.h>
 #endif
 
+#include "pretty_print.h"
 #include "debuglog.h"
 #include "listener_thread.h"
 #include "module.h"
@@ -58,7 +59,8 @@ runtime_allocate_available_cores()
 
 	/* Find the number of processors currently online */
 	runtime_total_online_processors = sysconf(_SC_NPROCESSORS_ONLN);
-	printf("\tCore Count (Online): %u\n", runtime_total_online_processors);
+
+	pretty_print_key_value("Core Count (Online)", "%u\n", runtime_total_online_processors);
 
 	/* If more than two cores are available, leave core 0 free to run OS tasks */
 	if (runtime_total_online_processors > 2) {
@@ -84,9 +86,9 @@ runtime_allocate_available_cores()
 		runtime_worker_threads_count = max_possible_workers;
 	}
 
-	printf("\tListener core ID: %u\n", LISTENER_THREAD_CORE_ID);
-	printf("\tFirst Worker core ID: %u\n", runtime_first_worker_processor);
-	printf("\tWorker core count: %u\n", runtime_worker_threads_count);
+	pretty_print_key_value("Listener core ID", "%u\n", LISTENER_THREAD_CORE_ID);
+	pretty_print_key_value("First Worker core ID", "%u\n", runtime_first_worker_processor);
+	pretty_print_key_value("Worker core count", "%u\n", runtime_worker_threads_count);
 }
 
 /**
@@ -184,7 +186,7 @@ runtime_configure()
 	} else {
 		panic("Invalid scheduler policy: %s. Must be {EDF|FIFO}\n", scheduler_policy);
 	}
-	printf("\tScheduler Policy: %s\n", scheduler_print(scheduler));
+	pretty_print_key_value("Scheduler Policy", "%s\n", scheduler_print(scheduler));
 
 	/* Sigalrm Handler Technique */
 	char *sigalrm_policy = getenv("SLEDGE_SIGALRM_HANDLER");
@@ -197,12 +199,13 @@ runtime_configure()
 	} else {
 		panic("Invalid sigalrm policy: %s. Must be {BROADCAST|TRIAGED}\n", sigalrm_policy);
 	}
-	printf("\tSigalrm Policy: %s\n", runtime_print_sigalrm_handler(runtime_sigalrm_handler));
+	pretty_print_key_value("Sigalrm Policy", "%s\n", runtime_print_sigalrm_handler(runtime_sigalrm_handler));
 
 	/* Runtime Preemption Toggle */
 	char *preempt_disable = getenv("SLEDGE_DISABLE_PREEMPTION");
 	if (preempt_disable != NULL && strcmp(preempt_disable, "false") != 0) runtime_preemption_enabled = false;
-	printf("\tPreemption: %s\n", runtime_preemption_enabled ? "Enabled" : "Disabled");
+	pretty_print_key_value("Preemption", "%s\n",
+	                       runtime_preemption_enabled ? PRETTY_PRINT_GREEN_ENABLED : PRETTY_PRINT_RED_DISABLED);
 
 	/* Runtime Quantum */
 	char *quantum_raw = getenv("SLEDGE_QUANTUM_US");
@@ -213,7 +216,7 @@ runtime_configure()
 			panic("SLEDGE_QUANTUM_US must be less than 999999 ms, saw %ld\n", quantum);
 		runtime_quantum_us = (uint32_t)quantum;
 	}
-	printf("\tQuantum: %u us\n", runtime_quantum_us);
+	pretty_print_key_value("Quantum", "%u us\n", runtime_quantum_us);
 
 	sandbox_perf_log_init();
 }
@@ -221,97 +224,113 @@ runtime_configure()
 void
 log_compiletime_config()
 {
-	printf("Static Compiler Flags:\n");
+	/* System Stuff */
+	printf("System Flags:\n");
+
+	pretty_print_key("Architecture");
+#if defined(aarch64)
+	printf("aarch64\n");
+#elif defined(x86_64)
+	printf("x86_64\n");
+#endif
+
+	pretty_print_key_value("Page Size", "%lu\n", PAGE_SIZE);
+
+	/* Feature Toggles */
+	printf("Static Compiler Flags (Features):\n");
+
 #ifdef ADMISSIONS_CONTROL
-	printf("\tAdmissions Control: Enabled\n");
+	pretty_print_key_enabled("Admissions Control");
 #else
-	printf("\tAdmissions Control: Disabled\n");
+	pretty_print_key_disabled("Admissions Control");
 #endif
 
-#ifdef NDEBUG
-	printf("\tAssertions and Debug Logs: Disabled\n");
+	/* Debugging Flags */
+	printf("Static Compiler Flags (Debugging):\n");
+
+#ifndef NDEBUG
+	pretty_print_key_enabled("Assertions and Debug Logs");
 #else
-	printf("\tAssertions and Debug Logs: Enabled\n");
+	pretty_print_key_disabled("Assertions and Debug Logs");
 #endif
 
+	pretty_print_key("Logging to");
 #ifdef LOG_TO_FILE
-	printf("\tLogging to: %s\n", RUNTIME_LOG_FILE);
+	printf("%s\n", RUNTIME_LOG_FILE);
 #else
-	printf("\tLogging to: STDOUT and STDERR\n");
+	printf("STDOUT and STDERR\n");
 #endif
 
-#if defined(aarch64)
-	printf("\tArchitecture: %s\n", "aarch64");
-#elif defined(x86_64)
-	printf("\tArchitecture: %s\n", "x86_64");
+#ifdef LOG_ADMISSIONS_CONTROL
+	pretty_print_key_enabled("Log Admissions Control");
+#else
+	pretty_print_key_disabled("Log Admissions Control");
 #endif
 
-	printf("\tPage Size: %lu\n", PAGE_SIZE);
-
-#ifdef LOG_HTTP_PARSER
-	printf("\tLog HTTP Parser: Enabled\n");
+#ifdef LOG_CONTEXT_SWITCHES
+	pretty_print_key_enabled("Log Context Switches");
 #else
-	printf("\tLog HTTP Parser: Disabled\n");
+	pretty_print_key_disabled("Log Context Switches");
 #endif
 
-#ifdef LOG_STATE_CHANGES
-	printf("\tLog State Changes: Enabled\n");
+#ifdef LOG_HTTP_PARSER
+	pretty_print_key_enabled("Log HTTP Parser");
 #else
-	printf("\tLog State Changes: Disabled\n");
+	pretty_print_key_disabled("Log HTTP Parser");
 #endif
 
 #ifdef LOG_LOCK_OVERHEAD
-	printf("\tLog Lock Overhead: Enabled\n");
+	pretty_print_key_enabled("Log Lock Overhead");
 #else
-	printf("\tLog Lock Overhead: Disabled\n");
+	pretty_print_key_disabled("Log Lock Overhead");
 #endif
 
-#ifdef LOG_CONTEXT_SWITCHES
-	printf("\tLog Context Switches: Enabled\n");
+#ifdef LOG_MODULE_LOADING
+	pretty_print_key_enabled("Log Module Loading");
 #else
-	printf("\tLog Context Switches: Disabled\n");
+	pretty_print_key_disabled("Log Module Loading");
 #endif
 
-#ifdef LOG_ADMISSIONS_CONTROL
-	printf("\tLog Admissions Control: Enabled\n");
+#ifdef LOG_PREEMPTION
+	pretty_print_key_enabled("Log Preemption");
 #else
-	printf("\tLog Admissions Control: Disabled\n");
+	pretty_print_key_disabled("Log Preemption");
 #endif
 
 #ifdef LOG_REQUEST_ALLOCATION
-	printf("\tLog Request Allocation: Enabled\n");
+	pretty_print_key_enabled("Log Request Allocation");
 #else
-	printf("\tLog Request Allocation: Disabled\n");
+	pretty_print_key_disabled("Log Request Allocation");
 #endif
 
-#ifdef LOG_PREEMPTION
-	printf("\tLog Preemption: Enabled\n");
+#ifdef LOG_SOFTWARE_INTERRUPT_COUNTS
+	pretty_print_key_enabled("Log Software Interrupt Counts");
 #else
-	printf("\tLog Preemption: Disabled\n");
+	pretty_print_key_disabled("Log Software Interrupt Counts");
 #endif
 
-#ifdef LOG_MODULE_LOADING
-	printf("\tLog Module Loading: Enabled\n");
+#ifdef LOG_STATE_CHANGES
+	pretty_print_key_enabled("Log State Changes");
 #else
-	printf("\tLog Module Loading: Disabled\n");
+	pretty_print_key_disabled("Log State Changes");
 #endif
 
 #ifdef LOG_TOTAL_REQS_RESPS
-	printf("\tLog Total Reqs/Resps: Enabled\n");
+	pretty_print_key_enabled("Log Total Reqs/Resps");
 #else
-	printf("\tLog Total Reqs/Resps: Disabled\n");
+	pretty_print_key_disabled("Log Total Reqs/Resps");
 #endif
 
 #ifdef LOG_SANDBOX_COUNT
-	printf("\tLog Sandbox Count: Enabled\n");
+	pretty_print_key_enabled("Log Sandbox Count");
 #else
-	printf("\tLog Sandbox Count: Disabled\n");
+	pretty_print_key_disabled("Log Sandbox Count");
 #endif
 
 #ifdef LOG_LOCAL_RUNQUEUE
-	printf("\tLog Local Runqueue: Enabled\n");
+	pretty_print_key_enabled("Log Local Runqueue");
 #else
-	printf("\tLog Local Runqueue: Disabled\n");
+	pretty_print_key_disabled("Log Local Runqueue");
 #endif
 }
 
@@ -333,9 +352,9 @@ main(int argc, char **argv)
 	runtime_processor_speed_MHz = runtime_get_processor_speed_MHz();
 	if (unlikely(runtime_processor_speed_MHz == 0)) panic("Failed to detect processor speed\n");
 
-	software_interrupt_set_interval_duration(runtime_quantum_us * runtime_processor_speed_MHz);
+	int heading_length = 30;
 
-	printf("\tProcessor Speed: %u MHz\n", runtime_processor_speed_MHz);
+	pretty_print_key_value("Processor Speed", "%u MHz\n", runtime_processor_speed_MHz);
 
 	runtime_set_resource_limits_to_max();
 	runtime_allocate_available_cores();

runtime/src/runtime.c

@@ -46,8 +46,7 @@ runtime_cleanup()
 	if (runtime_worker_threads_argument) free(runtime_worker_threads_argument);
 	if (runtime_worker_threads) free(runtime_worker_threads);
 
-	software_interrupt_deferred_sigalrm_max_print();
-	software_interrupt_deferred_sigalrm_max_free();
+	software_interrupt_cleanup();
 	exit(EXIT_SUCCESS);
 }
 
@@ -81,11 +80,11 @@ runtime_set_resource_limits_to_max()
 			snprintf(max, uint64_t_max_digits, "%lu", limit.rlim_max);
 		}
 		if (limit.rlim_cur == limit.rlim_max) {
-			printf("\t%s: %s\n", resource_names[i], max);
+			pretty_print_key_value(resource_names[i], "%s\n", max);
 		} else {
 			limit.rlim_cur = limit.rlim_max;
 			if (setrlimit(resource, &limit) < 0) panic_err();
-			printf("\t%s: %s (Increased from %s)\n", resource_names[i], max, lim);
+			pretty_print_key_value(resource_names[i], "%s (Increased from %s)\n", max, lim);
 		}
 	}
 }

runtime/src/software_interrupt.c

@@ -3,6 +3,7 @@
 #include <signal.h>
 #include <sys/time.h>
 #include <string.h>
+#include <stdatomic.h>
 #include <stdint.h>
 #include <stdlib.h>
 #include <threads.h>
@@ -21,52 +22,10 @@
 #include "sandbox_types.h"
 #include "scheduler.h"
 #include "software_interrupt.h"
+#include "software_interrupt_counts.h"
 
-/*******************
- * Process Globals *
- ******************/
-
-static uint64_t software_interrupt_interval_duration_in_cycles;
-
-/******************
- * Thread Globals *
- *****************/
-
-thread_local _Atomic static volatile sig_atomic_t software_interrupt_SIGALRM_kernel_count = 0;
-thread_local _Atomic static volatile sig_atomic_t software_interrupt_SIGALRM_thread_count = 0;
-thread_local _Atomic static volatile sig_atomic_t software_interrupt_SIGUSR_count         = 0;
-thread_local _Atomic volatile sig_atomic_t        software_interrupt_deferred_sigalrm     = 0;
-thread_local _Atomic volatile sig_atomic_t        software_interrupt_signal_depth         = 0;
-
-_Atomic volatile sig_atomic_t *software_interrupt_deferred_sigalrm_max;
-
-void
-software_interrupt_deferred_sigalrm_max_alloc()
-{
-#ifdef LOG_DEFERRED_SIGALRM_MAX
-	software_interrupt_deferred_sigalrm_max = calloc(runtime_worker_threads_count, sizeof(_Atomic(sig_atomic_t)));
-#endif
-}
-
-void
-software_interrupt_deferred_sigalrm_max_free()
-{
-#ifdef LOG_DEFERRED_SIGALRM_MAX
-	if (software_interrupt_deferred_sigalrm_max) free((void *)software_interrupt_deferred_sigalrm_max);
-#endif
-}
-
-void
-software_interrupt_deferred_sigalrm_max_print()
-{
-#ifdef LOG_DEFERRED_SIGALRM_MAX
-	printf("Max Deferred Sigalrms\n");
-	for (int i = 0; i < runtime_worker_threads_count; i++) {
-		printf("Worker %d: %d\n", i, software_interrupt_deferred_sigalrm_max[i]);
-	}
-	fflush(stdout);
-#endif
-}
+thread_local _Atomic volatile sig_atomic_t handler_depth;
+thread_local _Atomic volatile sig_atomic_t deferred_sigalrm;
 
 /***************************************
  * Externs
@@ -78,16 +37,22 @@ extern pthread_t *runtime_worker_threads;
  * Private Static Inlines *
  *************************/
 
+static inline void
+defer_sigalrm()
+{
+	atomic_fetch_add(&deferred_sigalrm, 1);
+}
+
 /**
  * A POSIX signal is delivered to only one thread.
  * This function broadcasts the sigalarm signal to all other worker threads
  */
 static inline void
-sigalrm_propagate_workers(siginfo_t *signal_info)
+propagate_sigalrm(siginfo_t *signal_info)
 {
 	/* Signal was sent directly by the kernel, so forward to other threads */
 	if (signal_info->si_code == SI_KERNEL) {
-		atomic_fetch_add(&software_interrupt_SIGALRM_kernel_count, 1);
+		software_interrupt_counts_sigalrm_kernel_increment();
 		for (int i = 0; i < runtime_worker_threads_count; i++) {
 			/* All threads should have been initialized */
 			assert(runtime_worker_threads[i] != 0);
@@ -109,23 +74,12 @@ sigalrm_propagate_workers(siginfo_t *signal_info)
 			}
 		}
 	} else {
-		atomic_fetch_add(&software_interrupt_SIGALRM_thread_count, 1);
+		software_interrupt_counts_sigalrm_thread_increment();
 		/* Signal forwarded from another thread. Just confirm it resulted from pthread_kill */
 		assert(signal_info->si_code == SI_TKILL);
 	}
 }
 
-/**
- * Validates that the thread running the signal handler is a known worker thread
- */
-static inline void
-software_interrupt_validate_worker()
-{
-#ifndef NDEBUG
-	if (listener_thread_is_running()) panic("The listener thread unexpectedly received a signal!");
-#endif
-}
-
 /**
  * The handler function for Software Interrupts (signals)
  * SIGALRM is executed periodically by an interval timer, causing preemption of the current sandbox
@@ -144,55 +98,57 @@ software_interrupt_handle_signals(int signal_type, siginfo_t *signal_info, void
 	assert(runtime_preemption_enabled);
 
 	/* Signals should not nest */
-	assert(software_interrupt_signal_depth == 0);
-	atomic_fetch_add(&software_interrupt_signal_depth, 1);
+	assert(handler_depth == 0);
+	atomic_fetch_add(&handler_depth, 1);
 
 	ucontext_t *    interrupted_context = (ucontext_t *)interrupted_context_raw;
 	struct sandbox *current_sandbox     = current_sandbox_get();
 
 	switch (signal_type) {
 	case SIGALRM: {
-		sigalrm_propagate_workers(signal_info);
+		propagate_sigalrm(signal_info);
 
-		/* Nonpreemptive, so defer */
-		if (!sandbox_is_preemptable(current_sandbox)) {
-			atomic_fetch_add(&software_interrupt_deferred_sigalrm, 1);
-			goto done;
+		if (sandbox_is_preemptable(current_sandbox)) {
+			scheduler_preemptive_sched(interrupted_context);
+		} else {
+			defer_sigalrm();
 		}
 
-		scheduler_preemptive_sched(interrupted_context);
-
-		goto done;
+		break;
 	}
 	case SIGUSR1: {
 		assert(current_sandbox);
 		assert(current_sandbox->state == SANDBOX_PREEMPTED);
 		assert(current_sandbox->ctxt.variant == ARCH_CONTEXT_VARIANT_SLOW);
 
-		atomic_fetch_add(&software_interrupt_SIGUSR_count, 1);
+		software_interrupt_counts_sigusr_increment();
 #ifdef LOG_PREEMPTION
-		debuglog("Total SIGUSR1 Received: %d\n", software_interrupt_SIGUSR_count);
+		debuglog("Total SIGUSR1 Received: %d\n", sigusr_count);
 		debuglog("Restoring sandbox: %lu, Stack %llu\n", current_sandbox->id,
 		         current_sandbox->ctxt.mctx.gregs[REG_RSP]);
 #endif
 		/* It is the responsibility of the caller to invoke current_sandbox_set before triggering the SIGUSR1 */
 		scheduler_preemptive_switch_to(interrupted_context, current_sandbox);
-		goto done;
+
+		break;
 	}
 	default: {
+		const char *signal_name = strsignal(signal_type);
 		switch (signal_info->si_code) {
 		case SI_TKILL:
-			panic("Unexpectedly received signal %d from a thread kill, but we have no handler\n",
-			      signal_type);
+			panic("software_interrupt_handle_signals unexpectedly received signal %s from a thread kill\n",
+			      signal_name);
 		case SI_KERNEL:
-			panic("Unexpectedly received signal %d from the kernel, but we have no handler\n", signal_type);
+			panic("software_interrupt_handle_signals unexpectedly received signal %s from the kernel\n",
+			      signal_name);
 		default:
-			panic("Anomolous Signal\n");
+			panic("software_interrupt_handle_signals unexpectedly received signal %s with si_code %d\n",
+			      signal_name, signal_info->si_code);
 		}
 	}
 	}
-done:
-	atomic_fetch_sub(&software_interrupt_signal_depth, 1);
+
+	atomic_fetch_sub(&handler_depth, 1);
 	return;
 }
 
@@ -240,7 +196,6 @@ software_interrupt_disarm_timer(void)
 	}
 }
 
-
 /**
  * Initialize software Interrupts
  * Register softint_handler to execute on SIGALRM and SIGUSR1
@@ -276,11 +231,12 @@ software_interrupt_initialize(void)
 		}
 	}
 
-	software_interrupt_deferred_sigalrm_max_alloc();
+	software_interrupt_counts_alloc();
 }
 
 void
-software_interrupt_set_interval_duration(uint64_t cycles)
+software_interrupt_cleanup()
 {
-	software_interrupt_interval_duration_in_cycles = cycles;
+	software_interrupt_counts_deferred_sigalrm_max_update(deferred_sigalrm);
+	software_interrupt_counts_log();
 }

runtime/src/software_interrupt_counts.c

@@ -0,0 +1,26 @@
+#include "software_interrupt_counts.h"
+#include "pretty_print.h"
+
+_Atomic volatile sig_atomic_t *software_interrupt_counts_deferred_sigalrm_max;
+_Atomic volatile sig_atomic_t *software_interrupt_counts_deferred_sigalrm_replay;
+_Atomic volatile sig_atomic_t *software_interrupt_counts_sigalrm_kernel;
+_Atomic volatile sig_atomic_t *software_interrupt_counts_sigalrm_thread;
+_Atomic volatile sig_atomic_t *software_interrupt_counts_sigusr;
+
+void
+software_interrupt_counts_log()
+{
+#ifdef LOG_SOFTWARE_INTERRUPT_COUNTS
+	for (int i = 0; i < runtime_worker_threads_count; i++) {
+		printf("Worker %d:\n", i);
+		pretty_print_key_value("Deferred Sigalrm Max", "%12d\n",
+		                       software_interrupt_counts_deferred_sigalrm_max[i]);
+		pretty_print_key_value("Deferred Sigalrm Replay", "%12d\n",
+		                       software_interrupt_counts_deferred_sigalrm_replay[i]);
+		pretty_print_key_value("Siglarm Kernel Count", "%12d\n", software_interrupt_counts_sigalrm_kernel[i]);
+		pretty_print_key_value("Siglarm Thread Count", "%12d\n", software_interrupt_counts_sigalrm_thread[i]);
+		pretty_print_key_value("Sigusr Count", "%12d\n", software_interrupt_counts_sigusr[i]);
+	}
+	fflush(stdout);
+#endif
+}