From c64a45b21406004305c4c12e593d518e4cb5cf6b Mon Sep 17 00:00:00 2001 From: xiaosuGW Date: Mon, 4 Oct 2021 13:27:39 -0400 Subject: [PATCH] fix one bug of SRSF --- runtime/include/sandbox_functions.h | 26 ++++++++++---------- runtime/include/sandbox_set_as_initialized.h | 2 ++ runtime/include/sandbox_set_as_running.h | 9 ++++++- runtime/include/scheduler.h | 10 +++++++- runtime/src/main.c | 3 ++- 5 files changed, 34 insertions(+), 16 deletions(-) diff --git a/runtime/include/sandbox_functions.h b/runtime/include/sandbox_functions.h index 247535e..8d96fd1 100644 --- a/runtime/include/sandbox_functions.h +++ b/runtime/include/sandbox_functions.h @@ -114,7 +114,7 @@ sandbox_get_srsf_priority(void *element) if (remaining_slack < 0) { return 0; } - return remaining_slack; + return remaining_slack; }; /** @@ -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); diff --git a/runtime/include/sandbox_set_as_initialized.h b/runtime/include/sandbox_set_as_initialized.h index 28ccb19..59169b1 100644 --- a/runtime/include/sandbox_set_as_initialized.h +++ b/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)); diff --git a/runtime/include/sandbox_set_as_running.h b/runtime/include/sandbox_set_as_running.h index 5ff333c..92a4437 100644 --- a/runtime/include/sandbox_set_as_running.h +++ b/runtime/include/sandbox_set_as_running.h @@ -3,10 +3,12 @@ #include #include +#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; } diff --git a/runtime/include/scheduler.h b/runtime/include/scheduler.h index af94fd2..6b6dc46 100644 --- a/runtime/include/scheduler.h +++ b/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); } diff --git a/runtime/src/main.c b/runtime/src/main.c index 5c5ee12..921e1b4 100644 --- a/runtime/src/main.c +++ b/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();