diff --git a/runtime/include/sandbox_functions.h b/runtime/include/sandbox_functions.h index 0c8976c..4626f07 100644 --- a/runtime/include/sandbox_functions.h +++ b/runtime/include/sandbox_functions.h @@ -89,7 +89,7 @@ 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; - uint64_t queued_duration = sandbox->allocation_timestamp - sandbox->request_arrival_timestamp; + uint64_t queued_duration = sandbox->timestamp_of.allocation - sandbox->timestamp_of.request_arrival; /* * Assumption: A sandbox is never able to free pages. If linear memory management diff --git a/runtime/include/sandbox_send_response.h b/runtime/include/sandbox_send_response.h index 4dfb4e3..e206ce1 100644 --- a/runtime/include/sandbox_send_response.h +++ b/runtime/include/sandbox_send_response.h @@ -96,7 +96,7 @@ sandbox_send_response(struct sandbox *sandbox) /* Capture Timekeeping data for end-to-end latency */ uint64_t end_time = __getcycles(); - sandbox->total_time = end_time - sandbox->request_arrival_timestamp; + sandbox->total_time = end_time - sandbox->timestamp_of.request_arrival; int rc; int sent = 0; diff --git a/runtime/include/sandbox_set_as_blocked.h b/runtime/include/sandbox_set_as_blocked.h index d066518..33d7cd7 100644 --- a/runtime/include/sandbox_set_as_blocked.h +++ b/runtime/include/sandbox_set_as_blocked.h @@ -22,7 +22,7 @@ sandbox_set_as_blocked(struct sandbox *sandbox, sandbox_state_t last_state) assert(sandbox); uint64_t now = __getcycles(); - uint64_t duration_of_last_state = now - sandbox->last_state_change_timestamp; + uint64_t duration_of_last_state = now - sandbox->timestamp_of.last_state_change; sandbox->state = SANDBOX_SET_AS_BLOCKED; @@ -38,8 +38,8 @@ sandbox_set_as_blocked(struct sandbox *sandbox, sandbox_state_t last_state) } } - sandbox->last_state_change_timestamp = now; - sandbox->state = SANDBOX_BLOCKED; + sandbox->timestamp_of.last_state_change = now; + sandbox->state = SANDBOX_BLOCKED; /* State Change Bookkeeping */ sandbox_state_log_transition(sandbox->id, last_state, SANDBOX_BLOCKED); diff --git a/runtime/include/sandbox_set_as_complete.h b/runtime/include/sandbox_set_as_complete.h index 9a4891d..3d8b476 100644 --- a/runtime/include/sandbox_set_as_complete.h +++ b/runtime/include/sandbox_set_as_complete.h @@ -24,13 +24,13 @@ sandbox_set_as_complete(struct sandbox *sandbox, sandbox_state_t last_state) assert(sandbox); uint64_t now = __getcycles(); - uint64_t duration_of_last_state = now - sandbox->last_state_change_timestamp; + uint64_t duration_of_last_state = now - sandbox->timestamp_of.last_state_change; sandbox->state = SANDBOX_SET_AS_COMPLETE; switch (last_state) { case SANDBOX_RETURNED: { - sandbox->completion_timestamp = now; + sandbox->timestamp_of.completion = now; sandbox->returned_duration += duration_of_last_state; break; } @@ -40,8 +40,8 @@ sandbox_set_as_complete(struct sandbox *sandbox, sandbox_state_t last_state) } } - sandbox->last_state_change_timestamp = now; - sandbox->state = SANDBOX_COMPLETE; + sandbox->timestamp_of.last_state_change = now; + sandbox->state = SANDBOX_COMPLETE; /* State Change Bookkeeping */ sandbox_state_log_transition(sandbox->id, last_state, SANDBOX_COMPLETE); diff --git a/runtime/include/sandbox_set_as_error.h b/runtime/include/sandbox_set_as_error.h index 575864b..207fb72 100644 --- a/runtime/include/sandbox_set_as_error.h +++ b/runtime/include/sandbox_set_as_error.h @@ -29,7 +29,7 @@ sandbox_set_as_error(struct sandbox *sandbox, sandbox_state_t last_state) assert(sandbox); uint64_t now = __getcycles(); - uint64_t duration_of_last_state = now - sandbox->last_state_change_timestamp; + uint64_t duration_of_last_state = now - sandbox->timestamp_of.last_state_change; sandbox->state = SANDBOX_SET_AS_ERROR; diff --git a/runtime/include/sandbox_set_as_initialized.h b/runtime/include/sandbox_set_as_initialized.h index 5250a2e..aaeb5e9 100644 --- a/runtime/include/sandbox_set_as_initialized.h +++ b/runtime/include/sandbox_set_as_initialized.h @@ -29,9 +29,9 @@ sandbox_set_as_initialized(struct sandbox *sandbox, struct sandbox_request *sand 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->state = SANDBOX_SET_AS_INITIALIZED; + sandbox->timestamp_of.request_arrival = sandbox_request->request_arrival_timestamp; + sandbox->timestamp_of.allocation = allocation_timestamp; + sandbox->state = SANDBOX_SET_AS_INITIALIZED; /* Initialize the sandbox's context, stack, and instruction pointer */ /* stack.start points to the bottom of the usable stack, so add stack_size to get to top */ @@ -47,8 +47,8 @@ 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->last_state_change_timestamp = allocation_timestamp; /* We use arg to include alloc */ - sandbox->state = SANDBOX_INITIALIZED; + sandbox->timestamp_of.last_state_change = 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); diff --git a/runtime/include/sandbox_set_as_returned.h b/runtime/include/sandbox_set_as_returned.h index 06cceae..98347bb 100644 --- a/runtime/include/sandbox_set_as_returned.h +++ b/runtime/include/sandbox_set_as_returned.h @@ -25,14 +25,14 @@ sandbox_set_as_returned(struct sandbox *sandbox, sandbox_state_t last_state) assert(sandbox); uint64_t now = __getcycles(); - uint64_t duration_of_last_state = now - sandbox->last_state_change_timestamp; + uint64_t duration_of_last_state = now - sandbox->timestamp_of.last_state_change; sandbox->state = SANDBOX_SET_AS_RETURNED; switch (last_state) { case SANDBOX_RUNNING: { - sandbox->response_timestamp = now; - sandbox->total_time = now - sandbox->request_arrival_timestamp; + sandbox->timestamp_of.response = now; + sandbox->total_time = now - sandbox->timestamp_of.request_arrival; sandbox->running_duration += duration_of_last_state; local_runqueue_delete(sandbox); sandbox_free_linear_memory(sandbox); @@ -44,8 +44,8 @@ sandbox_set_as_returned(struct sandbox *sandbox, sandbox_state_t last_state) } } - sandbox->last_state_change_timestamp = now; - sandbox->state = SANDBOX_RETURNED; + sandbox->timestamp_of.last_state_change = now; + sandbox->state = SANDBOX_RETURNED; /* State Change Bookkeeping */ sandbox_state_log_transition(sandbox->id, last_state, SANDBOX_RETURNED); diff --git a/runtime/include/sandbox_set_as_runnable.h b/runtime/include/sandbox_set_as_runnable.h index a34d72b..9028734 100644 --- a/runtime/include/sandbox_set_as_runnable.h +++ b/runtime/include/sandbox_set_as_runnable.h @@ -25,7 +25,7 @@ sandbox_set_as_runnable(struct sandbox *sandbox, sandbox_state_t last_state) assert(sandbox); uint64_t now = __getcycles(); - uint64_t duration_of_last_state = now - sandbox->last_state_change_timestamp; + uint64_t duration_of_last_state = now - sandbox->timestamp_of.last_state_change; sandbox->state = SANDBOX_SET_AS_RUNNABLE; @@ -51,7 +51,7 @@ sandbox_set_as_runnable(struct sandbox *sandbox, sandbox_state_t last_state) } } - sandbox->last_state_change_timestamp = now; + sandbox->timestamp_of.last_state_change = now; sandbox->state = SANDBOX_RUNNABLE; /* State Change Bookkeeping */ diff --git a/runtime/include/sandbox_set_as_running.h b/runtime/include/sandbox_set_as_running.h index b46dece..655daa7 100644 --- a/runtime/include/sandbox_set_as_running.h +++ b/runtime/include/sandbox_set_as_running.h @@ -13,7 +13,7 @@ sandbox_set_as_running(struct sandbox *sandbox, sandbox_state_t last_state) assert(sandbox); uint64_t now = __getcycles(); - uint64_t duration_of_last_state = now - sandbox->last_state_change_timestamp; + uint64_t duration_of_last_state = now - sandbox->timestamp_of.last_state_change; sandbox->state = SANDBOX_SET_AS_RUNNING; @@ -31,8 +31,8 @@ sandbox_set_as_running(struct sandbox *sandbox, sandbox_state_t last_state) } } - sandbox->last_state_change_timestamp = now; - sandbox->state = SANDBOX_RUNNING; + sandbox->timestamp_of.last_state_change = now; + sandbox->state = SANDBOX_RUNNING; /* State Change Bookkeeping */ sandbox_state_log_transition(sandbox->id, last_state, SANDBOX_RUNNING); diff --git a/runtime/include/sandbox_summarize_page_allocations.h b/runtime/include/sandbox_summarize_page_allocations.h index e58b1b0..5137e11 100644 --- a/runtime/include/sandbox_summarize_page_allocations.h +++ b/runtime/include/sandbox_summarize_page_allocations.h @@ -22,8 +22,8 @@ sandbox_summarize_page_allocations(struct sandbox *sandbox) fprintf(sandbox_page_allocations_log, "%lu,%lu,%s,", sandbox->id, sandbox->running_duration, sandbox_state_stringify(sandbox->state)); - for (size_t i = 0; i < sandbox->page_allocation_timestamps_size; i++) - fprintf(sandbox_page_allocations_log, "%u,", sandbox->page_allocation_timestamps[i]); + for (size_t i = 0; i < sandbox->timestamp_of.page_allocations_size; i++) + fprintf(sandbox_page_allocations_log, "%u,", sandbox->timestamp_of.page_allocations[i]); fprintf(sandbox_page_allocations_log, "\n"); #else diff --git a/runtime/include/sandbox_types.h b/runtime/include/sandbox_types.h index 92d8a35..afd81e5 100644 --- a/runtime/include/sandbox_types.h +++ b/runtime/include/sandbox_types.h @@ -35,25 +35,33 @@ struct sandbox_stack { uint32_t size; }; +struct sandbox_timestamps { + uint64_t last_state_change; /* Used for bookkeeping of actual execution time */ + uint64_t request_arrival; /* Timestamp when request is received */ + uint64_t allocation; /* Timestamp when sandbox is allocated */ + uint64_t response; /* Timestamp when response is sent */ + uint64_t completion; /* Timestamp when sandbox runs to completion */ +#ifdef LOG_SANDBOX_MEMORY_PROFILE + uint32_t page_allocations[SANDBOX_PAGE_ALLOCATION_TIMESTAMP_COUNT]; + size_t page_allocations_size; +#endif +}; + struct sandbox { uint64_t id; sandbox_state_t state; uint32_t sandbox_size; /* The struct plus enough buffer to hold the request or response (sized off largest) */ - /* Primitives that provide WebAssembly execution */ + /* WebAssembly Module State */ + struct module *module; /* the module this is an instance of */ + + /* WebAssembly Instance State */ struct arch_context ctxt; struct sandbox_stack stack; struct wasm_memory memory; - uint64_t request_arrival_timestamp; /* Timestamp when request is received */ - uint64_t allocation_timestamp; /* Timestamp when sandbox is allocated */ - uint64_t response_timestamp; /* Timestamp when response is sent */ - uint64_t completion_timestamp; /* Timestamp when sandbox runs to completion */ - uint64_t last_state_change_timestamp; /* Used for bookkeeping of actual execution time */ -#ifdef LOG_SANDBOX_MEMORY_PROFILE - uint32_t page_allocation_timestamps[SANDBOX_PAGE_ALLOCATION_TIMESTAMP_COUNT]; - size_t page_allocation_timestamps_size; -#endif + struct sandbox_timestamps timestamp_of; + /* Duration of time (in cycles) that the sandbox is in each state */ uint64_t initializing_duration; uint64_t runnable_duration; @@ -70,7 +78,6 @@ struct sandbox { */ uint64_t admissions_estimate; - struct module *module; /* the module this is an instance of */ int32_t arguments_offset; /* actual placement of arguments in the sandbox. */ void * arguments; /* arguments from request, must be of module->argument_count size. */ diff --git a/runtime/src/current_sandbox.c b/runtime/src/current_sandbox.c index 2df22e8..c390617 100644 --- a/runtime/src/current_sandbox.c +++ b/runtime/src/current_sandbox.c @@ -87,7 +87,7 @@ current_sandbox_start(void) current_sandbox_enable_preemption(sandbox); sandbox->return_value = module_main(current_module, argument_count, sandbox->arguments_offset); current_sandbox_disable_preemption(sandbox); - sandbox->completion_timestamp = __getcycles(); + sandbox->timestamp_of.completion = __getcycles(); /* Retrieve the result, construct the HTTP response, and send to client */ if (sandbox_send_response(sandbox) < 0) { @@ -97,7 +97,7 @@ current_sandbox_start(void) http_total_increment_2xx(); - sandbox->response_timestamp = __getcycles(); + sandbox->timestamp_of.response = __getcycles(); assert(sandbox->state == SANDBOX_RUNNING); sandbox_close_http(sandbox); diff --git a/runtime/src/memory/64bit_nix.c b/runtime/src/memory/64bit_nix.c index e7ac2e0..331fbdb 100644 --- a/runtime/src/memory/64bit_nix.c +++ b/runtime/src/memory/64bit_nix.c @@ -33,9 +33,9 @@ expand_memory(void) #ifdef LOG_SANDBOX_MEMORY_PROFILE // Cache the runtime of the first N page allocations - if (likely(sandbox->page_allocation_timestamps_size < SANDBOX_PAGE_ALLOCATION_TIMESTAMP_COUNT)) { - sandbox->page_allocation_timestamps[sandbox->page_allocation_timestamps_size++] = - sandbox->running_duration + (uint32_t)(__getcycles() - sandbox->last_state_change_timestamp); + if (likely(sandbox->timestamp_of.page_allocations_size < SANDBOX_PAGE_ALLOCATION_TIMESTAMP_COUNT)) { + sandbox->timestamp_of.page_allocations[sandbox->timestamp_of.page_allocations_size++] = + sandbox->running_duration + (uint32_t)(__getcycles() - sandbox->timestamp_of.last_state_change); } #endif diff --git a/runtime/src/sandbox.c b/runtime/src/sandbox.c index 08d50cf..6b8e424 100644 --- a/runtime/src/sandbox.c +++ b/runtime/src/sandbox.c @@ -146,10 +146,10 @@ err_stack_allocation_failed: * This is a degenerate sandbox that never successfully completed initialization, so we need to * hand jam some things to be able to cleanly transition to ERROR state */ - sandbox->state = SANDBOX_SET_AS_INITIALIZED; - sandbox->last_state_change_timestamp = now; + sandbox->state = SANDBOX_SET_AS_INITIALIZED; + sandbox->timestamp_of.last_state_change = now; #ifdef LOG_SANDBOX_MEMORY_PROFILE - sandbox->page_allocation_timestamps_size = 0; + sandbox->timestamp_of.page_allocations_size = 0; #endif ps_list_init_d(sandbox); err_memory_allocation_failed: