refactor: sandbox timestamps

master
Sean McBride 4 years ago
parent 8578176b98
commit c80dfa1db5

@ -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

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

@ -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,7 +38,7 @@ sandbox_set_as_blocked(struct sandbox *sandbox, sandbox_state_t last_state)
}
}
sandbox->last_state_change_timestamp = now;
sandbox->timestamp_of.last_state_change = now;
sandbox->state = SANDBOX_BLOCKED;
/* State Change Bookkeeping */

@ -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,7 +40,7 @@ sandbox_set_as_complete(struct sandbox *sandbox, sandbox_state_t last_state)
}
}
sandbox->last_state_change_timestamp = now;
sandbox->timestamp_of.last_state_change = now;
sandbox->state = SANDBOX_COMPLETE;
/* State Change Bookkeeping */

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

@ -29,8 +29,8 @@ 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->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 */
@ -47,7 +47,7 @@ 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->timestamp_of.last_state_change = allocation_timestamp; /* We use arg to include alloc */
sandbox->state = SANDBOX_INITIALIZED;
/* State Change Bookkeeping */

@ -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,7 +44,7 @@ sandbox_set_as_returned(struct sandbox *sandbox, sandbox_state_t last_state)
}
}
sandbox->last_state_change_timestamp = now;
sandbox->timestamp_of.last_state_change = now;
sandbox->state = SANDBOX_RETURNED;
/* State Change Bookkeeping */

@ -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 */

@ -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,7 +31,7 @@ sandbox_set_as_running(struct sandbox *sandbox, sandbox_state_t last_state)
}
}
sandbox->last_state_change_timestamp = now;
sandbox->timestamp_of.last_state_change = now;
sandbox->state = SANDBOX_RUNNING;
/* State Change Bookkeeping */

@ -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

@ -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. */

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

@ -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

@ -147,9 +147,9 @@ err_stack_allocation_failed:
* 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->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:

Loading…
Cancel
Save