From e7723e333120cdbb083d5feaee72ceb4656c60b6 Mon Sep 17 00:00:00 2001 From: Sean McBride Date: Sat, 10 Oct 2020 15:59:36 -0400 Subject: [PATCH] fix: correct http-parser bug --- runtime/experiments/applications/client1.sh | 21 +++- runtime/include/http_request.h | 2 + runtime/include/runtime.h | 7 +- runtime/include/sandbox.h | 7 +- runtime/include/sandbox_request.h | 6 + runtime/src/http_parser_settings.c | 125 ++++++++++---------- runtime/src/local_runqueue_minheap.c | 7 +- runtime/src/runtime.c | 20 ++-- runtime/src/sandbox.c | 102 ++++++---------- runtime/src/worker_thread.c | 9 +- 10 files changed, 150 insertions(+), 156 deletions(-) diff --git a/runtime/experiments/applications/client1.sh b/runtime/experiments/applications/client1.sh index 0c19bdf..1f840de 100755 --- a/runtime/experiments/applications/client1.sh +++ b/runtime/experiments/applications/client1.sh @@ -1,6 +1,23 @@ #!/bin/bash -for i in {1..10000}; do +expected_result="This is q handw__tten +examp(e for _0CR, +Write as good as yo_ c4n." + +success_count=0 +total_count=1000 + +for ((i = 0; i < total_count; i++)); do echo "$i" - curl -H 'Expect:' -H "Content-Type: text/plain" --data-binary "@handwrt1.pnm" localhost:10000 + result=$(curl -H 'Expect:' -H "Content-Type: text/plain" --data-binary "@handwrt1.pnm" localhost:10000 2>/dev/null) + # echo "$result" + if [[ "$result" == "$expected_result" ]]; then + success_count=$((success_count + 1)) + else + echo "FAIL" + echo "Expected $expected_result" + echo "Was $result" + fi done + +echo "$success_count / $total_count" diff --git a/runtime/include/http_request.h b/runtime/include/http_request.h index 2312bdc..0c8da42 100644 --- a/runtime/include/http_request.h +++ b/runtime/include/http_request.h @@ -6,7 +6,9 @@ /* all in-memory ptrs.. don't mess around with that! */ struct http_header { char *key; + int key_length; char *value; + int value_length; }; struct http_request { diff --git a/runtime/include/runtime.h b/runtime/include/runtime.h index d086a9e..c9e76fa 100644 --- a/runtime/include/runtime.h +++ b/runtime/include/runtime.h @@ -35,12 +35,15 @@ extern pthread_t runtime_worker_threads[]; extern uint32_t runtime_worker_threads_count; extern uint64_t runtime_admissions_capacity; +/* Listener Core Counts */ +extern _Atomic uint32_t runtime_total_requests; +extern _Atomic uint32_t runtime_total_sandbox_requests; +extern _Atomic uint32_t runtime_total_5XX_responses; + #ifdef LOG_TOTAL_REQS_RESPS /* Counts to track requests and responses */ -extern _Atomic uint32_t runtime_total_requests; extern _Atomic uint32_t runtime_total_2XX_responses; extern _Atomic uint32_t runtime_total_4XX_responses; -extern _Atomic uint32_t runtime_total_5XX_responses; #endif #ifdef LOG_SANDBOX_TOTALS diff --git a/runtime/include/sandbox.h b/runtime/include/sandbox.h index 3bb6ef8..8886f67 100644 --- a/runtime/include/sandbox.h +++ b/runtime/include/sandbox.h @@ -51,6 +51,7 @@ typedef enum } sandbox_state_t; 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) */ @@ -331,9 +332,9 @@ sandbox_print_perf(struct sandbox *sandbox) "running: %u, " "blocked: %u, " "returned: %u\n", - sandbox->request_arrival_timestamp, 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->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); } static inline void diff --git a/runtime/include/sandbox_request.h b/runtime/include/sandbox_request.h index 8b39469..71e3cd6 100644 --- a/runtime/include/sandbox_request.h +++ b/runtime/include/sandbox_request.h @@ -8,6 +8,7 @@ #include "runtime.h" struct sandbox_request { + uint64_t id; struct module * module; char * arguments; int socket_descriptor; @@ -40,6 +41,11 @@ sandbox_request_allocate(struct module *module, char *arguments, int socket_desc { struct sandbox_request *sandbox_request = (struct sandbox_request *)malloc(sizeof(struct sandbox_request)); assert(sandbox_request); + + /* Sets the ID to the value before the increment */ + sandbox_request->id = atomic_fetch_add(&runtime_total_sandbox_requests, 1); + assert(runtime_total_sandbox_requests + runtime_total_5XX_responses <= runtime_total_requests); + sandbox_request->module = module; sandbox_request->arguments = arguments; sandbox_request->socket_descriptor = socket_descriptor; diff --git a/runtime/src/http_parser_settings.c b/runtime/src/http_parser_settings.c index f3cff0c..a259aac 100644 --- a/runtime/src/http_parser_settings.c +++ b/runtime/src/http_parser_settings.c @@ -24,10 +24,12 @@ int http_parser_settings_on_url(http_parser *parser, const char *at, size_t length) { struct sandbox *sandbox = (struct sandbox *)parser->data; - if (sandbox->http_request.message_end || sandbox->http_request.header_end) return 0; + + assert(!sandbox->http_request.message_end); + assert(!sandbox->http_request.header_end); #ifdef LOG_HTTP_PARSER - debuglog("sandbox: %lu\n", sandbox->request_arrival_timestamp); + debuglog("sandbox: %lu, length: %zu, Content \"%.*s\"\n", sandbox->id, length, (int)length, at); assert(strncmp(sandbox->module->name, (at + 1), length - 1) == 0); #endif @@ -45,15 +47,16 @@ http_parser_settings_on_message_begin(http_parser *parser) struct sandbox * sandbox = (struct sandbox *)parser->data; struct http_request *http_request = &sandbox->http_request; - if (sandbox->http_request.message_end || sandbox->http_request.header_end) return 0; + assert(!sandbox->http_request.message_end); + assert(!sandbox->http_request.header_end); #ifdef LOG_HTTP_PARSER - debuglog("sandbox: %lu\n", sandbox->request_arrival_timestamp); + debuglog("sandbox: %lu\n", sandbox->id); #endif http_request->message_begin = true; http_request->last_was_value = true; /* should always start with a header */ - sandbox->is_repeat_header = false; + return 0; } @@ -72,43 +75,30 @@ http_parser_settings_on_header_field(http_parser *parser, const char *at, size_t struct sandbox * sandbox = (struct sandbox *)parser->data; struct http_request *http_request = &sandbox->http_request; - if (sandbox->http_request.message_end || sandbox->http_request.header_end) return 0; - #ifdef LOG_HTTP_PARSER - debuglog("sandbox: %lu\n", sandbox->request_arrival_timestamp); + debuglog("sandbox: %lu, length: %zu, Content \"%.*s\"\n", sandbox->id, length, (int)length, at); #endif - /* Previous name continues */ + assert(!sandbox->http_request.message_end); + assert(!sandbox->http_request.header_end); + if (http_request->last_was_value == false) { + /* Previous key continues */ assert(http_request->header_count > 0); - strncat(http_request->headers[http_request->header_count].key, at, length); - return 0; - } - - /* - * We receive repeat headers for an unknown reason, so we need to ignore repeat headers - * This probably means that the headers are getting reparsed, so for the sake of performance - * this should be fixed upstream - */ - - -#ifdef LOG_HTTP_PARSER - for (int i = 0; i < http_request->header_count; i++) { - if (strncmp(http_request->headers[i].key, at, length) == 0) { - debuglog("Repeat header!\n"); - assert(0); - sandbox->is_repeat_header = true; - break; + if (unlikely(http_request->headers[http_request->header_count].key_length + length + > HTTP_MAX_HEADER_LENGTH)) { + return -1; } - } -#endif - - if (!sandbox->is_repeat_header) { - if (unlikely(http_request->header_count >= HTTP_MAX_HEADER_COUNT)) { return -1; } - if (unlikely(length > HTTP_MAX_HEADER_LENGTH)) { return -1; } - http_request->headers[http_request->header_count++].key = (char *)at; - http_request->last_was_value = false; - sandbox->is_repeat_header = false; + http_request->headers[http_request->header_count].key_length += length; + return 0; + } else { + /* Start of new key */ + if (unlikely(http_request->header_count >= HTTP_MAX_HEADER_COUNT)) return -1; + if (unlikely(length > HTTP_MAX_HEADER_LENGTH)) return -1; + http_request->header_count++; + http_request->headers[http_request->header_count - 1].key = (char *)at; + http_request->headers[http_request->header_count - 1].key_length = length; + http_request->last_was_value = false; } return 0; @@ -128,21 +118,24 @@ http_parser_settings_on_header_value(http_parser *parser, const char *at, size_t struct sandbox * sandbox = (struct sandbox *)parser->data; struct http_request *http_request = &sandbox->http_request; - if (http_request->message_end || http_request->header_end) return 0; #ifdef LOG_HTTP_PARSER - debuglog("sandbox: %lu\n", sandbox->request_arrival_timestamp); + debuglog("sandbox: %lu, length: %zu, Content \"%.*s\"\n", sandbox->id, length, (int)length, at); #endif - // TODO: If last_was_value is already true, we might need to append to value - + assert(!sandbox->http_request.message_end); + assert(!sandbox->http_request.header_end); - /* it is from the sandbox's request_response_data, should persist. */ - if (!sandbox->is_repeat_header) { + if (!http_request->last_was_value) { if (unlikely(length >= HTTP_MAX_HEADER_VALUE_LENGTH)) return -1; - http_request->headers[http_request->header_count - 1].value = (char *)at; - http_request->last_was_value = true; + http_request->headers[http_request->header_count - 1].value = (char *)at; + http_request->headers[http_request->header_count - 1].value_length = length; + } else { + assert(http_request->headers[http_request->header_count - 1].value_length > 0); + http_request->headers[http_request->header_count - 1].value_length += length; } + + http_request->last_was_value = true; return 0; } @@ -156,16 +149,21 @@ http_parser_settings_on_header_end(http_parser *parser) { struct sandbox * sandbox = (struct sandbox *)parser->data; struct http_request *http_request = &sandbox->http_request; - if (http_request->message_end || http_request->header_end) return 0; + + assert(!sandbox->http_request.message_end); + assert(!sandbox->http_request.header_end); #ifdef LOG_HTTP_PARSER - debuglog("sandbox: %lu\n", sandbox->request_arrival_timestamp); + debuglog("sandbox: %lu\n", sandbox->id); #endif http_request->header_end = true; return 0; } +const size_t http_methods_len = 8; +const char * http_methods[http_methods_len] = { "OPTIONS", "GET", "HEAD", "POST", "PUT", "DELETE", "TRACE", "CONNECT" }; + /** * http-parser callback called for HTTP Bodies * Assigns the parsed data to the http_request body of the sandbox struct @@ -181,38 +179,34 @@ http_parser_settings_on_body(http_parser *parser, const char *at, size_t length) struct sandbox * sandbox = (struct sandbox *)parser->data; struct http_request *http_request = &sandbox->http_request; - if (http_request->message_end) return 0; + assert(sandbox->http_request.header_end); + assert(!sandbox->http_request.message_end); -#ifdef LOG_HTTP_PARSER - debuglog("sandbox: %lu\n", sandbox->request_arrival_timestamp); -#endif /* Assumption: We should never exceed the buffer we're reusing */ assert(http_request->body_length + length <= sandbox->module->max_request_size); if (!http_request->body) { +#ifdef LOG_HTTP_PARSER + debuglog("Setting start of body!\n"); +#endif /* If this is the first invocation of the callback, just set */ http_request->body = (char *)at; http_request->body_length = length; } else { #ifdef LOG_HTTP_PARSER - debuglog("Body: %p, Existing Length: %d\n", http_request->body, http_request->body_length); - - debuglog("Expected Offset %d, Actual Offset: %lu\n", http_request->body_length, - at - http_request->body); - - /* Attempt to copy and print the entire body */ - uint64_t possible_body_len = at - http_request->body; - char test_buffer[possible_body_len + length + 1]; - strncpy(test_buffer, http_request->body, possible_body_len); - test_buffer[length] = '\0'; - debuglog("http_parser_settings_on_body: len %lu, content: %s\n", possible_body_len, test_buffer); + debuglog("Appending to existing body!\n"); #endif - http_request->body_length += length; } +#ifdef LOG_HTTP_PARSER + int capped_len = length > 1000 ? 1000 : length; + debuglog("sandbox: %lu, length: %zu, Content(up to 1000 chars) \"%.*s\"\n", sandbox->id, length, + (int)capped_len, at); +#endif + return 0; } @@ -227,12 +221,15 @@ http_parser_settings_on_msg_end(http_parser *parser) struct sandbox * sandbox = (struct sandbox *)parser->data; struct http_request *http_request = &sandbox->http_request; - if (http_request->message_end) return 0; + assert(sandbox->http_request.header_end); + assert(!sandbox->http_request.message_end); + #ifdef LOG_HTTP_PARSER - debuglog("sandbox: %lu\n", sandbox->request_arrival_timestamp); + debuglog("sandbox: %lu\n", sandbox->id); #endif http_request->message_end = true; + return 0; } diff --git a/runtime/src/local_runqueue_minheap.c b/runtime/src/local_runqueue_minheap.c index 5c9d75f..578f0ac 100644 --- a/runtime/src/local_runqueue_minheap.c +++ b/runtime/src/local_runqueue_minheap.c @@ -59,10 +59,7 @@ local_runqueue_minheap_delete(struct sandbox *sandbox) assert(sandbox != NULL); int rc = priority_queue_delete(&local_runqueue_minheap, sandbox); - if (rc == -1) { - panic("Tried to delete sandbox %lu from runqueue, but was not present\n", - sandbox->request_arrival_timestamp); - } + if (rc == -1) panic("Tried to delete sandbox %lu from runqueue, but was not present\n", sandbox->id); } /** @@ -143,7 +140,7 @@ local_runqueue_minheap_preempt(ucontext_t *user_context) if (global_deadline < local_deadline) { #ifdef LOG_PREEMPTION debuglog("Sandbox %lu has deadline of %lu. Trying to preempt for request with %lu\n", - current_sandbox->request_arrival_timestamp, local_deadline, global_deadline); + current_sandbox->id, local_deadline, global_deadline); #endif int return_code = global_request_scheduler_remove_if_earlier(&sandbox_request, local_deadline); diff --git a/runtime/src/runtime.c b/runtime/src/runtime.c index 765a95d..365fa95 100644 --- a/runtime/src/runtime.c +++ b/runtime/src/runtime.c @@ -22,11 +22,17 @@ int runtime_epoll_file_descriptor; _Atomic uint64_t runtime_admitted; uint64_t runtime_admissions_capacity; +/* Listener Core Bookkeeping */ +_Atomic uint32_t runtime_total_requests = 0; + +/* Sandbox Requests + 5XX Responses (Rejections) should always equal total requests */ +_Atomic uint32_t runtime_total_sandbox_requests = 0; +_Atomic uint32_t runtime_total_5XX_responses = 0; + #ifdef LOG_TOTAL_REQS_RESPS -_Atomic uint32_t runtime_total_requests = 0; +/* 2XX + 4XX should equal sandboxes */ _Atomic uint32_t runtime_total_2XX_responses = 0; _Atomic uint32_t runtime_total_4XX_responses = 0; -_Atomic uint32_t runtime_total_5XX_responses = 0; void runtime_log_requests_responses() @@ -89,11 +95,13 @@ runtime_log_sandbox_states() void runtime_initialize(void) { -#ifdef LOG_TOTAL_REQS_RESPS atomic_init(&runtime_total_requests, 0); + atomic_init(&runtime_total_sandbox_requests, 0); + atomic_init(&runtime_total_5XX_responses, 0); + +#ifdef LOG_TOTAL_REQS_RESPS atomic_init(&runtime_total_2XX_responses, 0); atomic_init(&runtime_total_4XX_responses, 0); - atomic_init(&runtime_total_5XX_responses, 0); #endif #ifdef LOG_SANDBOX_TOTALS atomic_init(&runtime_total_freed_requests, 0); @@ -157,9 +165,7 @@ listener_thread_reject(int client_socket) sent += rc; }; -#ifdef LOG_TOTAL_REQS_RESPS atomic_fetch_add(&runtime_total_5XX_responses, 1); -#endif close: if (close(client_socket) < 0) panic("Error closing client socket - %s", strerror(errno)); @@ -255,9 +261,7 @@ listener_thread_main(void *dummy) module->name); } -#ifdef LOG_TOTAL_REQS_RESPS atomic_fetch_add(&runtime_total_requests, 1); -#endif /* Perform Admission Control */ diff --git a/runtime/src/sandbox.c b/runtime/src/sandbox.c index 2bdcdbd..8dad762 100644 --- a/runtime/src/sandbox.c +++ b/runtime/src/sandbox.c @@ -64,18 +64,18 @@ sandbox_receive_and_parse_client_request(struct sandbox *sandbox) while (!sandbox->http_request.message_end) { /* Read from the Socket */ - ssize_t length_read = recv(sandbox->client_socket_descriptor, - &sandbox->request_response_data[sandbox->request_response_data_length], - sandbox->module->max_request_size - sandbox->request_response_data_length, - 0); - - /* Unexpected client shutdown.. or is this just EOF */ - if (length_read == 0 && !sandbox->http_request.message_end) { - debuglog("Client Shutdown Socket\n"); - goto err; - } - if (length_read < 0) { + /* Structured to closely follow usage example at https://github.com/nodejs/http-parser */ + http_parser * parser = &sandbox->http_parser; + const http_parser_settings *settings = http_parser_settings_get(); + + int fd = sandbox->client_socket_descriptor; + char * buf = &sandbox->request_response_data[sandbox->request_response_data_length]; + size_t len = sandbox->module->max_request_size - sandbox->request_response_data_length; + + ssize_t recved = recv(fd, buf, len, 0); + + if (recved < 0) { if (errno == EAGAIN) { worker_thread_block_current_sandbox(); continue; @@ -87,46 +87,20 @@ sandbox_receive_and_parse_client_request(struct sandbox *sandbox) } } - - if (sandbox->http_request.message_end) { - sandbox->request_response_data_length += length_read; - break; - }; - #ifdef LOG_HTTP_PARSER - debuglog("http_parser_execute(%p, %p, %p, %lu)", &sandbox->http_parser, http_parser_settings_get(), - &sandbox->request_response_data[sandbox->request_response_data_length], length_read); + debuglog("Sandbox: %lu http_parser_execute(%p, %p, %p, %lu)", sandbox->id, parser, settings, buf, len); #endif + size_t nparsed = http_parser_execute(parser, settings, buf, recved); - http_parser_execute(&sandbox->http_parser, http_parser_settings_get(), - &sandbox->request_response_data[sandbox->request_response_data_length], - length_read); - - - /* Try to parse what we've read */ - /* TODO: Consider 0 as EOF? */ - size_t length_parsed = - http_parser_execute(&sandbox->http_parser, http_parser_settings_get(), - &sandbox->request_response_data[sandbox->request_response_data_length], - length_read); - - if (sandbox->http_request.message_end) { - sandbox->request_response_data_length += length_read; - break; - }; - - // size_t length_parsed = sandbox_parse_http_request(sandbox, length_read); - if (length_parsed != length_read) { + if (nparsed != recved) { debuglog("Error: %s, Description: %s\n", http_errno_name(sandbox->http_parser.status_code), http_errno_description(sandbox->http_parser.status_code)); - debuglog("Length Parsed %zu, Length Read %zu\n", length_parsed, length_read); + debuglog("Length Parsed %zu, Length Read %zu\n", nparsed, recved); debuglog("Error parsing socket %d\n", sandbox->client_socket_descriptor); goto err; } - sandbox->request_response_data_length += length_read; - - debuglog("After Read: %lu", sandbox->request_response_data_length); + sandbox->request_response_data_length += nparsed; } @@ -405,7 +379,7 @@ err: #ifdef LOG_TOTAL_REQS_RESPS if (rc >= 0) { atomic_fetch_add(&runtime_total_4XX_responses, 1); - debuglog("At %llu, Sandbox %lu - 4XX\n", __getcycles(), sandbox->request_arrival_timestamp); + debuglog("At %llu, Sandbox %lu - 4XX\n", __getcycles(), sandbox->id); } #endif @@ -523,6 +497,7 @@ sandbox_set_as_initialized(struct sandbox *sandbox, struct sandbox_request *sand #ifdef LOG_STATE_CHANGES debuglog("Sandbox %lu | Uninitialized => Initialized\n", sandbox_request->request_arrival_timestamp); #endif + sandbox->id = sandbox_request->id; sandbox->admissions_estimate = sandbox_request->admissions_estimate; sandbox->request_arrival_timestamp = sandbox_request->request_arrival_timestamp; @@ -575,8 +550,7 @@ sandbox_set_as_runnable(struct sandbox *sandbox, sandbox_state_t last_state) sandbox->state = SANDBOX_SET_AS_RUNNABLE; #ifdef LOG_STATE_CHANGES - debuglog("Sandbox %lu | %s => Runnable\n", sandbox->request_arrival_timestamp, - sandbox_state_stringify(last_state)); + debuglog("Sandbox %lu | %s => Runnable\n", sandbox->id, sandbox_state_stringify(last_state)); #endif switch (last_state) { @@ -597,7 +571,7 @@ sandbox_set_as_runnable(struct sandbox *sandbox, sandbox_state_t last_state) break; } default: { - panic("Sandbox %lu | Illegal transition from %s to Runnable\n", sandbox->request_arrival_timestamp, + panic("Sandbox %lu | Illegal transition from %s to Runnable\n", sandbox->id, sandbox_state_stringify(last_state)); } } @@ -631,8 +605,7 @@ sandbox_set_as_running(struct sandbox *sandbox, sandbox_state_t last_state) sandbox->state = SANDBOX_SET_AS_RUNNING; #ifdef LOG_STATE_CHANGES - debuglog("Sandbox %lu | %s => Running\n", sandbox->request_arrival_timestamp, - sandbox_state_stringify(last_state)); + debuglog("Sandbox %lu | %s => Running\n", sandbox->id, sandbox_state_stringify(last_state)); #endif switch (last_state) { @@ -653,7 +626,7 @@ sandbox_set_as_running(struct sandbox *sandbox, sandbox_state_t last_state) break; } default: { - panic("Sandbox %lu | Illegal transition from %s to Running\n", sandbox->request_arrival_timestamp, + panic("Sandbox %lu | Illegal transition from %s to Running\n", sandbox->id, sandbox_state_stringify(last_state)); } } @@ -684,8 +657,7 @@ sandbox_set_as_preempted(struct sandbox *sandbox, sandbox_state_t last_state) sandbox->state = SANDBOX_SET_AS_PREEMPTED; #ifdef LOG_STATE_CHANGES - debuglog("Sandbox %lu | %s => Preempted\n", sandbox->request_arrival_timestamp, - sandbox_state_stringify(last_state)); + debuglog("Sandbox %lu | %s => Preempted\n", sandbox->id, sandbox_state_stringify(last_state)); #endif switch (last_state) { @@ -698,7 +670,7 @@ sandbox_set_as_preempted(struct sandbox *sandbox, sandbox_state_t last_state) break; } default: { - panic("Sandbox %lu | Illegal transition from %s to Preempted\n", sandbox->request_arrival_timestamp, + panic("Sandbox %lu | Illegal transition from %s to Preempted\n", sandbox->id, sandbox_state_stringify(last_state)); } } @@ -726,8 +698,7 @@ sandbox_set_as_blocked(struct sandbox *sandbox, sandbox_state_t last_state) sandbox->state = SANDBOX_SET_AS_BLOCKED; #ifdef LOG_STATE_CHANGES - debuglog("Sandbox %lu | %s => Blocked\n", sandbox->request_arrival_timestamp, - sandbox_state_stringify(last_state)); + debuglog("Sandbox %lu | %s => Blocked\n", sandbox->id, sandbox_state_stringify(last_state)); #endif switch (last_state) { @@ -741,7 +712,7 @@ sandbox_set_as_blocked(struct sandbox *sandbox, sandbox_state_t last_state) break; } default: { - panic("Sandbox %lu | Illegal transition from %s to Blocked\n", sandbox->request_arrival_timestamp, + panic("Sandbox %lu | Illegal transition from %s to Blocked\n", sandbox->id, sandbox_state_stringify(last_state)); } } @@ -770,8 +741,7 @@ sandbox_set_as_returned(struct sandbox *sandbox, sandbox_state_t last_state) sandbox->state = SANDBOX_SET_AS_RETURNED; #ifdef LOG_STATE_CHANGES - debuglog("Sandbox %lu | %s => Returned\n", sandbox->request_arrival_timestamp, - sandbox_state_stringify(last_state)); + debuglog("Sandbox %lu | %s => Returned\n", sandbox->id, sandbox_state_stringify(last_state)); #endif switch (last_state) { @@ -788,7 +758,7 @@ sandbox_set_as_returned(struct sandbox *sandbox, sandbox_state_t last_state) break; } default: { - panic("Sandbox %lu | Illegal transition from %s to Returned\n", sandbox->request_arrival_timestamp, + panic("Sandbox %lu | Illegal transition from %s to Returned\n", sandbox->id, sandbox_state_stringify(last_state)); } } @@ -819,8 +789,7 @@ sandbox_set_as_error(struct sandbox *sandbox, sandbox_state_t last_state) sandbox->state = SANDBOX_SET_AS_ERROR; #ifdef LOG_STATE_CHANGES - debuglog("Sandbox %lu | %s => Error\n", sandbox->request_arrival_timestamp, - sandbox_state_stringify(last_state)); + debuglog("Sandbox %lu | %s => Error\n", sandbox->id, sandbox_state_stringify(last_state)); #endif switch (last_state) { @@ -842,7 +811,7 @@ sandbox_set_as_error(struct sandbox *sandbox, sandbox_state_t last_state) break; } default: { - panic("Sandbox %lu | Illegal transition from %s to Error\n", sandbox->request_arrival_timestamp, + panic("Sandbox %lu | Illegal transition from %s to Error\n", sandbox->id, sandbox_state_stringify(last_state)); } } @@ -885,8 +854,7 @@ sandbox_set_as_complete(struct sandbox *sandbox, sandbox_state_t last_state) sandbox->state = SANDBOX_SET_AS_COMPLETE; #ifdef LOG_STATE_CHANGES - debuglog("Sandbox %lu | %s => Complete\n", sandbox->request_arrival_timestamp, - sandbox_state_stringify(last_state)); + debuglog("Sandbox %lu | %s => Complete\n", sandbox->id, sandbox_state_stringify(last_state)); #endif switch (last_state) { @@ -900,7 +868,7 @@ sandbox_set_as_complete(struct sandbox *sandbox, sandbox_state_t last_state) break; } default: { - panic("Sandbox %lu | Illegal transition from %s to Error\n", sandbox->request_arrival_timestamp, + panic("Sandbox %lu | Illegal transition from %s to Error\n", sandbox->id, sandbox_state_stringify(last_state)); } } @@ -1025,7 +993,7 @@ sandbox_free(struct sandbox *sandbox) errno = 0; rc = munmap(stkaddr, stksz); if (rc == -1) { - debuglog("Failed to unmap stack of Sandbox %lu\n", sandbox->request_arrival_timestamp); + debuglog("Failed to unmap stack of Sandbox %lu\n", sandbox->id); goto err_free_stack_failed; }; @@ -1039,7 +1007,7 @@ sandbox_free(struct sandbox *sandbox) errno = 0; rc = munmap(sandbox, sandbox_address_space_size); if (rc == -1) { - debuglog("Failed to unmap Sandbox %lu\n", sandbox->request_arrival_timestamp); + debuglog("Failed to unmap Sandbox %lu\n", sandbox->id); goto err_free_sandbox_failed; }; @@ -1049,5 +1017,5 @@ err_free_sandbox_failed: err_free_stack_failed: err: /* Errors freeing memory is a fatal error */ - panic("Failed to free Sandbox %lu\n", sandbox->request_arrival_timestamp); + panic("Failed to free Sandbox %lu\n", sandbox->id); } diff --git a/runtime/src/worker_thread.c b/runtime/src/worker_thread.c index 286aae3..2652c30 100644 --- a/runtime/src/worker_thread.c +++ b/runtime/src/worker_thread.c @@ -111,8 +111,8 @@ worker_thread_switch_to_sandbox(struct sandbox *next_sandbox) #ifdef LOG_CONTEXT_SWITCHES debuglog("Base Context (%s) > Sandbox %lu (%s)\n", - arch_context_variant_print(worker_thread_base_context.variant), - next_sandbox->request_arrival_timestamp, arch_context_variant_print(next_context->variant)); + arch_context_variant_print(worker_thread_base_context.variant), next_sandbox->id, + arch_context_variant_print(next_context->variant)); #endif arch_context_switch(NULL, next_context); @@ -127,8 +127,7 @@ worker_thread_switch_to_sandbox(struct sandbox *next_sandbox) struct arch_context *current_context = ¤t_sandbox->ctxt; #ifdef LOG_CONTEXT_SWITCHES - debuglog("Sandbox %lu > Sandbox %lu\n", current_sandbox->request_arrival_timestamp, - next_sandbox->request_arrival_timestamp); + debuglog("Sandbox %lu > Sandbox %lu\n", current_sandbox->id, next_sandbox->id); #endif /* Switch to the associated context. */ @@ -157,7 +156,7 @@ worker_thread_switch_to_base_context() current_sandbox_set(NULL); #ifdef LOG_CONTEXT_SWITCHES - debuglog("Sandbox %lu (%s) > Base Context (%s)\n", current_sandbox->request_arrival_timestamp, + debuglog("Sandbox %lu (%s) > Base Context (%s)\n", current_sandbox->id, arch_context_variant_print(current_sandbox->ctxt.variant), arch_context_variant_print(worker_thread_base_context.variant)); #endif