fix one bug of SRSF

runtime/include/sandbox_functions.h

@@ -218,24 +218,24 @@ sandbox_mem_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->enqueue_timestamp)
+	uint64_t total_time_us = sandbox->total_time / runtime_processor_speed_MHz;
+        uint64_t queued_us     = (sandbox->allocation_timestamp - sandbox->enqueue_timestamp)
                              / runtime_processor_speed_MHz;
-        uint32_t initializing_us = sandbox->initializing_duration / runtime_processor_speed_MHz;
-        uint32_t runnable_us     = sandbox->runnable_duration / runtime_processor_speed_MHz;
-        uint32_t running_us      = sandbox->running_duration / runtime_processor_speed_MHz;
-        uint32_t blocked_us      = sandbox->blocked_duration / runtime_processor_speed_MHz;
-        uint32_t returned_us     = sandbox->returned_duration / runtime_processor_speed_MHz;
+        uint64_t initializing_us = sandbox->initializing_duration / runtime_processor_speed_MHz;
+        uint64_t runnable_us     = sandbox->runnable_duration / runtime_processor_speed_MHz;
+        uint64_t running_us      = sandbox->running_duration / runtime_processor_speed_MHz;
+        uint64_t blocked_us      = sandbox->blocked_duration / runtime_processor_speed_MHz;
+        uint64_t returned_us     = sandbox->returned_duration / runtime_processor_speed_MHz;
 
 	if (sandbox->module->next_module == NULL) {
-		uint32_t total_time = (sandbox->completion_timestamp - sandbox->request_arrival_timestamp) / runtime_processor_speed_MHz;
+		uint64_t total_time = (sandbox->completion_timestamp - sandbox->request_arrival_timestamp) / runtime_processor_speed_MHz;
                 bool miss_deadline = sandbox->completion_timestamp > sandbox->absolute_deadline ? true : false;
-		uint32_t delayed_us = (sandbox->completion_timestamp - sandbox->absolute_deadline) 
+		uint64_t delayed_us = (sandbox->completion_timestamp - sandbox->absolute_deadline) 
 					/ runtime_processor_speed_MHz;
                 if (miss_deadline) {
-                        mem_log("%lu miss deadline, delayed %u us, actual cost %u module name %s\n", sandbox->id, delayed_us, total_time, sandbox->module->name);
+                        mem_log("%u miss deadline, delayed %lu us, actual cost %lu module name %s\n", sandbox->id, delayed_us, total_time, sandbox->module->name);
                 } else {
-                        mem_log("%lu meet deadline, actual cost %u module name %s\n", sandbox->id, total_time, sandbox->module->name);
+                        mem_log("%u meet deadline, actual cost %lu module name %s\n", sandbox->id, total_time, sandbox->module->name);
                 }
         }
 
@@ -244,7 +244,7 @@ sandbox_mem_print_perf(struct sandbox *sandbox)
          * becomes more intelligent, then peak linear memory size needs to be tracked
          * seperately from current linear memory size.
          */
-        mem_log("%lu,%s():%d,%s,%u,%u,%u,%u,%u,%u,%u,%u,%u\n", sandbox->id,
+        mem_log("%u,%s():%d,%s,%lu,%lu,%lu,%lu,%lu,%lu,%lu,%lu,%u\n", sandbox->id,
                 sandbox->module->name, sandbox->module->port, sandbox_state_stringify(sandbox->state),
                 sandbox->module->relative_deadline_us, total_time_us, queued_us, initializing_us, runnable_us,
                 running_us, blocked_us, returned_us, sandbox->linear_memory_size);

runtime/include/sandbox_set_as_initialized.h

@@ -51,6 +51,8 @@ sandbox_set_as_initialized(struct sandbox *sandbox, struct sandbox_request *sand
 
 	/* Copy the socket descriptor, address, and arguments of the client invocation */
 	sandbox->absolute_deadline        = sandbox_request->absolute_deadline;
+	sandbox->remaining_slack	  = sandbox_request->remaining_slack;
+	sandbox->last_update_timestamp	  = sandbox_request->last_update_timestamp;
 	sandbox->arguments                = (void *)sandbox_request->arguments;
 	sandbox->client_socket_descriptor = sandbox_request->socket_descriptor;
 	memcpy(&sandbox->client_address, &sandbox_request->socket_address, sizeof(struct sockaddr));

runtime/include/sandbox_set_as_running.h

@@ -3,10 +3,12 @@
 #include <assert.h>
 #include <stdint.h>
 
+#include "memlogging.h"
 #include "arch/getcycles.h"
 #include "panic.h"
 #include "sandbox_types.h"
 
+extern uint64_t system_start_timestamp;
 static inline void
 sandbox_set_as_running(struct sandbox *sandbox, sandbox_state_t last_state)
 {
@@ -19,11 +21,16 @@ sandbox_set_as_running(struct sandbox *sandbox, sandbox_state_t last_state)
 
 	switch (last_state) {
 	case SANDBOX_RUNNABLE: {
-		sandbox->remaining_slack -= now - sandbox->last_update_timestamp;
+		uint64_t start_execution = now - system_start_timestamp;
+		uint64_t last = sandbox->last_update_timestamp;
+		uint32_t last_rs = sandbox->remaining_slack;
+		sandbox->remaining_slack -= (now - sandbox->last_update_timestamp);
 		sandbox->last_update_timestamp = now;  
 		sandbox->runnable_duration += duration_of_last_state;
 		current_sandbox_set(sandbox);
 		runtime_worker_threads_deadline[worker_thread_idx] = sandbox->absolute_deadline;
+                mem_log("time %lu sandbox starts running, request id:%d name %s obj=%p remaining slack %lu, last_rs %u now %lu last %lu \n", start_execution,
+                         sandbox->id, sandbox->module->name, sandbox, sandbox->remaining_slack, last_rs, now, last);
 		/* Does not handle context switch because the caller knows if we need to use fast or slow switched */
 		break;
 	}

runtime/include/scheduler.h

@@ -33,6 +33,7 @@ enum SCHEDULER
 
 extern enum SCHEDULER scheduler;
 extern _Atomic uint32_t scheduling_counter;
+extern uint64_t system_start_timestamp;
 
 static inline struct sandbox *
 scheduler_edf_get_next()
@@ -82,6 +83,11 @@ scheduler_srsf_get_next()
 	 * This will be placed at the head of the local runqueue */
 	if (global_remaining_slack < local_remaining_slack) {
 		if (global_request_scheduler_remove_if_earlier(&request, local_remaining_slack) == 0) {
+
+			uint64_t pop_time = __getcycles() - system_start_timestamp;
+                        mem_log("time %lu remove from GQ, request id:%d name %s remaining slack %lu\n", pop_time,
+                                        request->id, request->module->name, request->remaining_slack);
+			
 			assert(request != NULL);
 			struct sandbox *global = sandbox_allocate(request);
 			if (!global) goto err_allocate;
@@ -204,7 +210,7 @@ scheduler_preempt(ucontext_t *user_context)
 
 	struct sandbox *current = current_sandbox_get();
 	assert(current != NULL);
-	assert(current->state == SANDBOX_RUNNING);
+	//assert(current->state == SANDBOX_RUNNING);
 
 	struct sandbox *next = scheduler_get_next();
 	assert(next != NULL);
@@ -224,6 +230,7 @@ scheduler_preempt(ucontext_t *user_context)
 
 	/* Update current_sandbox to the next sandbox */
 	assert(next->state == SANDBOX_RUNNABLE);
+	//printf("scheduler_preempt...\n");
 	sandbox_set_as_running(next, SANDBOX_RUNNABLE);
 
 	switch (next->ctxt.variant) {
@@ -314,6 +321,7 @@ scheduler_switch_to(struct sandbox *next_sandbox)
 	}
 
 	scheduler_log_sandbox_switch(current_sandbox, next_sandbox);
+	//printf("scheduler_switch_to...\n");
 	sandbox_set_as_running(next_sandbox, next_sandbox->state);
 	arch_context_switch(current_context, next_context);
 }

runtime/src/main.c

@@ -30,7 +30,7 @@ uint32_t runtime_first_worker_processor  = 1;
 uint32_t runtime_processor_speed_MHz     = 0;
 uint32_t runtime_total_online_processors = 0;
 uint32_t runtime_worker_threads_count    = 0;
-
+uint64_t system_start_timestamp          = 0;
 
 FILE *runtime_sandbox_perf_log = NULL;
 
@@ -341,6 +341,7 @@ main(int argc, char **argv)
 		exit(-1);
 	}
 
+	system_start_timestamp = __getcycles();
 	printf("Starting the Sledge runtime\n");
 
 	log_compiletime_config();