Merge pull request #195 from gwsystems/friday-debugging

Assorted Debugging Improvements and Fixes
main
Sean McBride 4 years ago committed by GitHub
commit 72ed672b16
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23

@ -68,6 +68,7 @@ RUN apt-get update && apt-get install -y --no-install-recommends \
less \
openssh-client \
strace \
valgrind \
vim \
wabt

@ -6,7 +6,7 @@ endif
endif
TOTAL_CORES := $(shell getconf _NPROCESSORS_CONF)
PAGE_SIZE=$(shell getconf PAGESIZE)
PAGE_SIZE := $(shell getconf PAGESIZE)
# Compiler Settings
CC=clang
@ -15,16 +15,36 @@ CC_OPTIONS = -O3 -flto -g -pthread -D_GNU_SOURCE
# CC_OPTIONS for Debugging
# CC_OPTIONS = -O0 -g -pthread -D_GNU_SOURCE
# CFI Sanitizer
# CC_OPTIONS = -O0 -g -pthread -D_GNU_SOURCE -flto -fvisibility=default -fsanitize=cfi
# Undefined Sanitizer
# CC_OPTIONS = -O0 -g -pthread -D_GNU_SOURCE -fsanitize=undefined,float-divide-by-zero,unsigned-integer-overflow,implicit-conversion,local-bounds
# Clang SafeStack
# This actually seems to "solve" the segfaults
# https://clang.llvm.org/docs/SafeStack.html
# CC_OPTIONS = -O0 -g -pthread -D_GNU_SOURCE -fsanitize=safe-stack
# Memory Sanitizer
# https://clang.llvm.org/docs/MemorySanitizer.html
# https://github.com/google/sanitizers/wiki/MemorySanitizer
# CC_OPTIONS = -O0 -g -pthread -D_GNU_SOURCE -fsanitize=memory -fno-omit-frame-pointer
# Address Sanitizer
# https://clang.llvm.org/docs/AddressSanitizer.html
# CC_OPTIONS = -O0 -g -pthread -D_GNU_SOURCE -fsanitize=address -fno-omit-frame-pointer
BINARY_NAME=sledgert
# Feature Toggles
CFLAGS += -DADMISSIONS_CONTROL
# CFLAGS += -DADMISSIONS_CONTROL
# Debugging Flags
# Strips out calls to assert() and disables debuglog
CFLAGS += -DNDEBUG
# CFLAGS += -DNDEBUG
# Redirects debuglogs to /runtime/bin/sledge.log
# CFLAGS += -DLOG_TO_FILE

@ -24,6 +24,7 @@ __framework_sh__usage() {
echo " -t,--target=<target url> Execute as client against remote URL"
echo " -s,--serve Serve but do not run client"
echo " -d,--debug Debug under GDB but do not run client"
echo " -v,--valgrind Debug under Valgrind but do not run client"
echo " -p,--perf Run under perf. Limited to running on a baremetal Linux host!"
echo " -h,--help Display usage information"
}
@ -80,7 +81,7 @@ __framework_sh__parse_arguments() {
shift
;;
-p | --perf)
if [[ "$__framework_sh__role" == "perf" ]]; then
if [[ "$__framework_sh__role" == "client" ]]; then
echo "Cannot use -p,--perf with -t,--target"
__framework_sh__usage
return 1
@ -88,6 +89,15 @@ __framework_sh__parse_arguments() {
__framework_sh__role=perf
shift
;;
-v | --valgrind)
if [[ "$__framework_sh__role" == "client" ]]; then
echo "Cannot use -v,--valgrind with -t,--target"
__framework_sh__usage
return 1
fi
__framework_sh__role=valgrind
shift
;;
-h | --help)
__framework_sh__usage
exit 0
@ -229,6 +239,21 @@ __framework_sh__run_perf() {
perf record -g -s sledgert "$__framework_sh__application_directory/spec.json"
}
__framework_sh__run_valgrind() {
if (($# != 0)); then
printf "[ERR]\n"
panic "Invalid number of arguments. Saw $#. Expected 0."
return 1
fi
if ! command -v valgrind; then
echo "valgrind is not present."
exit 1
fi
valgrind --leak-check=full sledgert "$__framework_sh__application_directory/spec.json"
}
# Starts the Sledge Runtime under GDB
__framework_sh__run_debug() {
if (($# != 0)); then
@ -243,16 +268,16 @@ __framework_sh__run_debug() {
if [[ "$project_directory" != "/sledge/runtime" ]]; then
printf "It appears that you are not running in the container. Substituting path to match host environment\n"
gdb \
--eval-command="handle SIGUSR1 nostop" \
--eval-command="handle SIGPIPE nostop" \
--eval-command="handle SIGUSR1 noprint nostop" \
--eval-command="handle SIGPIPE noprint nostop" \
--eval-command="set pagination off" \
--eval-command="set substitute-path /sledge/runtime $project_directory" \
--eval-command="run $__framework_sh__application_directory/spec.json" \
sledgert
else
gdb \
--eval-command="handle SIGUSR1 nostop" \
--eval-command="handle SIGPIPE nostop" \
--eval-command="handle SIGUSR1 noprint nostop" \
--eval-command="handle SIGPIPE noprint nostop" \
--eval-command="set pagination off" \
--eval-command="run $__framework_sh__application_directory/spec.json" \
sledgert
@ -314,7 +339,7 @@ __framework_sh__create_and_export_results_directory() {
"both")
dir="$__framework_sh__application_directory/res/$__framework_sh__timestamp/$subdirectory"
;;
"client" | "server" | "debug" | "perf")
"client" | "server" | "debug" | "perf" | "valgrind")
dir="$__framework_sh__application_directory/res/$__framework_sh__timestamp"
;;
*)
@ -359,6 +384,9 @@ main() {
perf)
__framework_sh__run_perf
;;
valgrind)
__framework_sh__run_valgrind
;;
client)
__framework_sh__run_client
;;

@ -49,7 +49,7 @@ admissions_control_add(uint64_t admissions_estimate)
}
static inline void
admissions_control_substract(uint64_t admissions_estimate)
admissions_control_subtract(uint64_t admissions_estimate)
{
#ifdef ADMISSIONS_CONTROL
/* Assumption: Should never underflow */

@ -1,5 +1,6 @@
#pragma once
#include <arpa/inet.h>
#include <errno.h>
#include <unistd.h>
#include <string.h>
@ -13,14 +14,22 @@
static inline void
client_socket_close(int client_socket)
client_socket_close(int client_socket, struct sockaddr *client_address)
{
/* Should never close 0, 1, or 2 */
assert(client_socket != STDIN_FILENO);
assert(client_socket != STDOUT_FILENO);
assert(client_socket != STDERR_FILENO);
if (unlikely(close(client_socket) < 0)) debuglog("Error closing client socket - %s", strerror(errno));
if (unlikely(close(client_socket) < 0)) {
char client_address_text[INET6_ADDRSTRLEN] = {};
if (unlikely(inet_ntop(AF_INET, &client_address, client_address_text, INET6_ADDRSTRLEN) == NULL)) {
debuglog("Failed to log client_address: %s", strerror(errno));
}
debuglog("Error closing client socket %d associated with %s - %s", client_socket, client_address_text,
strerror(errno));
}
}

@ -51,7 +51,7 @@ struct module {
uint64_t max_memory; /* perhaps a specification of the module. (max 4GB) */
uint32_t relative_deadline_us;
uint64_t relative_deadline; /* cycles */
uint32_t reference_count; /* ref count how many instances exist here. */
_Atomic uint32_t reference_count; /* ref count how many instances exist here. */
struct indirect_table_entry indirect_table[INDIRECT_TABLE_SIZE];
struct sockaddr_in socket_address;
int socket_descriptor;
@ -101,7 +101,9 @@ struct module {
static inline void
module_acquire(struct module *module)
{
module->reference_count++;
assert(module->reference_count < UINT32_MAX);
atomic_fetch_add(&module->reference_count, 1);
return;
}
/**
@ -200,7 +202,9 @@ module_main(struct module *module, int32_t argc, int32_t argv)
static inline void
module_release(struct module *module)
{
module->reference_count--;
assert(module->reference_count > 0);
atomic_fetch_sub(&module->reference_count, 1);
return;
}
/**

@ -297,7 +297,7 @@ sandbox_close_http(struct sandbox *sandbox)
int rc = epoll_ctl(worker_thread_epoll_file_descriptor, EPOLL_CTL_DEL, sandbox->client_socket_descriptor, NULL);
if (unlikely(rc < 0)) panic_err();
client_socket_close(sandbox->client_socket_descriptor);
client_socket_close(sandbox->client_socket_descriptor, &sandbox->client_address);
}

@ -13,13 +13,13 @@
#include "sandbox_state.h"
struct sandbox_request {
uint64_t id;
struct module * module;
char * arguments;
int socket_descriptor;
struct sockaddr *socket_address;
uint64_t request_arrival_timestamp; /* cycles */
uint64_t absolute_deadline; /* cycles */
uint64_t id;
struct module * module;
char * arguments;
int socket_descriptor;
struct sockaddr socket_address;
uint64_t request_arrival_timestamp; /* cycles */
uint64_t absolute_deadline; /* cycles */
/*
* Unitless estimate of the instantaneous fraction of system capacity required to run the request
@ -74,10 +74,10 @@ sandbox_request_allocate(struct module *module, char *arguments, int socket_desc
/* Sets the ID to the value before the increment */
sandbox_request->id = sandbox_request_count_postfix_increment();
sandbox_request->module = module;
sandbox_request->arguments = arguments;
sandbox_request->socket_descriptor = socket_descriptor;
sandbox_request->socket_address = (struct sockaddr *)socket_address;
sandbox_request->module = module;
sandbox_request->arguments = arguments;
sandbox_request->socket_descriptor = socket_descriptor;
memcpy(&sandbox_request->socket_address, socket_address, sizeof(struct sockaddr));
sandbox_request->request_arrival_timestamp = request_arrival_timestamp;
sandbox_request->absolute_deadline = request_arrival_timestamp + module->relative_deadline;

@ -5,12 +5,12 @@
#ifndef PAGE_SIZE
#define PAGE_SIZE (1 << 12)
#define PAGE_SIZE (unsigned long)(1 << 12)
#endif
/* For this family of macros, do NOT pass zero as the pow2 */
#define round_to_pow2(x, pow2) (((unsigned long)(x)) & (~((pow2)-1)))
#define round_up_to_pow2(x, pow2) (round_to_pow2(((unsigned long)x) + (pow2)-1, (pow2)))
#define round_up_to_pow2(x, pow2) (round_to_pow2(((unsigned long)(x)) + (pow2)-1, (pow2)))
#define round_to_page(x) round_to_pow2(x, PAGE_SIZE)
#define round_up_to_page(x) round_up_to_pow2(x, PAGE_SIZE)

@ -36,8 +36,10 @@ local_completion_queue_add(struct sandbox *sandbox)
void
local_completion_queue_free()
{
struct sandbox *sandbox_iterator;
struct sandbox *buffer;
if (local_completion_queue_is_empty()) return;
struct sandbox *sandbox_iterator = NULL;
struct sandbox *buffer = NULL;
ps_list_foreach_del_d(&local_completion_queue, sandbox_iterator, buffer)
{

@ -60,7 +60,7 @@ local_runqueue_list_get_next()
return sandbox;
err_allocate:
client_socket_send(sandbox_request->socket_descriptor, 503);
client_socket_close(sandbox_request->socket_descriptor);
client_socket_close(sandbox_request->socket_descriptor, &sandbox->client_address);
free(sandbox_request);
err:
sandbox = NULL;

@ -92,7 +92,7 @@ local_runqueue_minheap_get_next()
sandbox = sandbox_allocate(sandbox_request);
if (!sandbox) {
client_socket_send(sandbox_request->socket_descriptor, 503);
client_socket_close(sandbox_request->socket_descriptor);
client_socket_close(sandbox_request->socket_descriptor, &sandbox->client_address);
free(sandbox_request);
continue;
};
@ -193,7 +193,7 @@ done:
return;
err_sandbox_allocate:
client_socket_send(sandbox_request->socket_descriptor, 503);
client_socket_close(sandbox_request->socket_descriptor);
client_socket_close(sandbox_request->socket_descriptor, &sandbox_request->socket_address);
debuglog("local_runqueue_minheap_preempt failed to allocate sandbox\n");
err:
goto done;

@ -41,7 +41,8 @@ expand_memory(void)
// TODO: Refactor to return RC signifying out-of-mem to caller. Issue #96.
if (map_result == MAP_FAILED) panic("Mapping of new memory failed");
if (local_sandbox_context_cache.linear_memory_size > sandbox->linear_memory_max_size)
panic("expand_memory - Out of Memory!\n");
panic("expand_memory - Out of Memory!. %u out of %lu\n", local_sandbox_context_cache.linear_memory_size,
sandbox->linear_memory_max_size);
local_sandbox_context_cache.linear_memory_size += WASM_PAGE_SIZE;

@ -147,7 +147,12 @@ module_new(char *name, char *path, int32_t argument_count, uint32_t stack_size,
memset(module, 0, sizeof(struct module));
/* Load the dynamic library *.so file with lazy function call binding and deep binding */
atomic_init(&module->reference_count, 0);
/* Load the dynamic library *.so file with lazy function call binding and deep binding
* RTLD_DEEPBIND is incompatible with certain clang sanitizers, so it might need to be temporarily disabled at
* times. See https://github.com/google/sanitizers/issues/611
*/
module->dynamic_library_handle = dlopen(path, RTLD_LAZY | RTLD_DEEPBIND);
if (module->dynamic_library_handle == NULL) {
fprintf(stderr, "Failed to open %s with error: %s\n", path, dlerror());
@ -193,8 +198,9 @@ module_new(char *name, char *path, int32_t argument_count, uint32_t stack_size,
strncpy(module->name, name, MODULE_MAX_NAME_LENGTH);
strncpy(module->path, path, MODULE_MAX_PATH_LENGTH);
module->argument_count = argument_count;
module->stack_size = round_up_to_page(stack_size == 0 ? WASM_STACK_SIZE : stack_size);
module->argument_count = argument_count;
module->stack_size = ((uint32_t)(round_up_to_page(stack_size == 0 ? WASM_STACK_SIZE : stack_size)));
debuglog("Stack Size: %u", module->stack_size);
module->max_memory = max_memory == 0 ? ((uint64_t)WASM_PAGE_SIZE * WASM_MAX_PAGES) : max_memory;
module->socket_descriptor = -1;
module->port = port;
@ -209,7 +215,7 @@ module_new(char *name, char *path, int32_t argument_count, uint32_t stack_size,
module->relative_deadline = (uint64_t)relative_deadline_us * runtime_processor_speed_MHz;
/* Admissions Control */
uint64_t expected_execution = expected_execution_us * runtime_processor_speed_MHz;
uint64_t expected_execution = (uint64_t)expected_execution_us * runtime_processor_speed_MHz;
admissions_info_initialize(&module->admissions_info, admissions_percentile, expected_execution,
module->relative_deadline);

@ -1,6 +1,7 @@
#include <signal.h>
#include <sched.h>
#include <sys/mman.h>
#include <arpa/inet.h>
#include "admissions_control.h"
#include "arch/context.h"
@ -165,7 +166,7 @@ listener_thread_main(void *dummy)
/*
* According to accept(2), it is possible that the the sockaddr structure client_address
* may be too small, resulting in data being truncated to fit. The appect call mutates
* may be too small, resulting in data being truncated to fit. The accept call mutates
* the size value to indicate that this is the case.
*/
if (address_length > sizeof(client_address)) {

@ -10,6 +10,7 @@
#include "http_total.h"
#include "local_completion_queue.h"
#include "local_runqueue.h"
#include "likely.h"
#include "panic.h"
#include "runtime.h"
#include "sandbox.h"
@ -85,6 +86,20 @@ sandbox_receive_and_parse_client_request(struct sandbox *sandbox)
}
}
/* Client request is malformed */
if (recved == 0 && !sandbox->http_request.message_end) {
char client_address_text[INET6_ADDRSTRLEN] = {};
if (unlikely(inet_ntop(AF_INET, &sandbox->client_address, client_address_text, INET6_ADDRSTRLEN)
== NULL)) {
debuglog("Failed to log client_address: %s", strerror(errno));
}
debuglog("Sandbox %lu: recv returned 0 before a complete request was received\n", sandbox->id);
debuglog("Socket: %d. Address: %s\n", fd, client_address_text);
http_request_print(&sandbox->http_request);
goto err;
}
#ifdef LOG_HTTP_PARSER
debuglog("Sandbox: %lu http_parser_execute(%p, %p, %p, %zu\n)", sandbox->id, parser, settings, buf,
recved);
@ -99,13 +114,6 @@ sandbox_receive_and_parse_client_request(struct sandbox *sandbox)
goto err;
}
if (recved == 0 && !sandbox->http_request.message_end) {
#ifdef LOG_HTTP_PARSER
debuglog("Sandbox %lu: Received 0, but parsing was incomplete\n", sandbox->id);
http_request_print(&sandbox->http_request);
#endif
goto err;
}
sandbox->request_response_data_length += nparsed;
}
@ -374,6 +382,8 @@ sandbox_allocate_memory(struct module *module)
goto alloc_failed;
}
assert(addr != NULL);
/* Set the struct sandbox, HTTP Req/Resp buffer, and the initial Wasm Pages as read/write */
errno = 0;
void *addr_rw = mmap(addr, sandbox_size + linear_memory_size, PROT_READ | PROT_WRITE,
@ -476,7 +486,7 @@ sandbox_set_as_initialized(struct sandbox *sandbox, struct sandbox_request *sand
sandbox->absolute_deadline = sandbox_request->absolute_deadline;
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));
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;
@ -504,7 +514,7 @@ sandbox_set_as_runnable(struct sandbox *sandbox, sandbox_state_t last_state)
assert(!software_interrupt_is_enabled());
uint64_t now = __getcycles();
uint32_t duration_of_last_state = now - sandbox->last_state_change_timestamp;
uint64_t duration_of_last_state = now - sandbox->last_state_change_timestamp;
sandbox->state = SANDBOX_SET_AS_RUNNABLE;
@ -553,7 +563,7 @@ sandbox_set_as_running(struct sandbox *sandbox, sandbox_state_t last_state)
assert(!software_interrupt_is_enabled());
uint64_t now = __getcycles();
uint32_t duration_of_last_state = now - sandbox->last_state_change_timestamp;
uint64_t duration_of_last_state = now - sandbox->last_state_change_timestamp;
sandbox->state = SANDBOX_SET_AS_RUNNING;
@ -599,7 +609,7 @@ sandbox_set_as_preempted(struct sandbox *sandbox, sandbox_state_t last_state)
assert(!software_interrupt_is_enabled());
uint64_t now = __getcycles();
uint32_t duration_of_last_state = now - sandbox->last_state_change_timestamp;
uint64_t duration_of_last_state = now - sandbox->last_state_change_timestamp;
sandbox->state = SANDBOX_SET_AS_PREEMPTED;
@ -638,7 +648,7 @@ sandbox_set_as_blocked(struct sandbox *sandbox, sandbox_state_t last_state)
assert(!software_interrupt_is_enabled());
uint64_t now = __getcycles();
uint32_t duration_of_last_state = now - sandbox->last_state_change_timestamp;
uint64_t duration_of_last_state = now - sandbox->last_state_change_timestamp;
sandbox->state = SANDBOX_SET_AS_BLOCKED;
@ -679,7 +689,7 @@ sandbox_set_as_returned(struct sandbox *sandbox, sandbox_state_t last_state)
assert(!software_interrupt_is_enabled());
uint64_t now = __getcycles();
uint32_t duration_of_last_state = now - sandbox->last_state_change_timestamp;
uint64_t duration_of_last_state = now - sandbox->last_state_change_timestamp;
sandbox->state = SANDBOX_SET_AS_RETURNED;
@ -726,7 +736,7 @@ sandbox_set_as_error(struct sandbox *sandbox, sandbox_state_t last_state)
assert(!software_interrupt_is_enabled());
uint64_t now = __getcycles();
uint32_t duration_of_last_state = now - sandbox->last_state_change_timestamp;
uint64_t duration_of_last_state = now - sandbox->last_state_change_timestamp;
sandbox->state = SANDBOX_SET_AS_ERROR;
@ -753,7 +763,7 @@ sandbox_set_as_error(struct sandbox *sandbox, sandbox_state_t last_state)
sandbox_summarize_page_allocations(sandbox);
#endif
sandbox_free_linear_memory(sandbox);
admissions_control_substract(sandbox->admissions_estimate);
admissions_control_subtract(sandbox->admissions_estimate);
/* Do not touch sandbox after adding to completion queue to avoid use-after-free bugs */
local_completion_queue_add(sandbox);
@ -777,7 +787,7 @@ sandbox_set_as_complete(struct sandbox *sandbox, sandbox_state_t last_state)
assert(!software_interrupt_is_enabled());
uint64_t now = __getcycles();
uint32_t duration_of_last_state = now - sandbox->last_state_change_timestamp;
uint64_t duration_of_last_state = now - sandbox->last_state_change_timestamp;
sandbox->state = SANDBOX_SET_AS_COMPLETE;
@ -801,7 +811,7 @@ sandbox_set_as_complete(struct sandbox *sandbox, sandbox_state_t last_state)
#endif
/* Admissions Control Post Processing */
admissions_info_update(&sandbox->module->admissions_info, sandbox->running_duration);
admissions_control_substract(sandbox->admissions_estimate);
admissions_control_subtract(sandbox->admissions_estimate);
/* Do not touch sandbox state after adding to completion queue to avoid use-after-free bugs */
local_completion_queue_add(sandbox);
@ -840,7 +850,7 @@ sandbox_allocate(struct sandbox_request *sandbox_request)
/* Allocate the Stack */
if (sandbox_allocate_stack(sandbox) < 0) {
error_message = "failed to allocate sandbox heap and linear memory";
error_message = "failed to allocate sandbox stack";
goto err_stack_allocation_failed;
}
sandbox->state = SANDBOX_ALLOCATED;
@ -879,6 +889,7 @@ sandbox_free_linear_memory(struct sandbox *sandbox)
{
int rc = munmap(sandbox->linear_memory_start, SANDBOX_MAX_MEMORY + PAGE_SIZE);
if (rc == -1) panic("sandbox_free_linear_memory - munmap failed\n");
sandbox->linear_memory_start = NULL;
}
/**
@ -908,14 +919,17 @@ sandbox_free(struct sandbox *sandbox)
};
/* Free Sandbox Linear Address Space
struct sandbox | HTTP Buffer | 4GB of Wasm Linear Memory | Guard Page
sandbox_size includes the struct and HTTP buffer */
size_t sandbox_address_space_size = sandbox->sandbox_size + sandbox->linear_memory_max_size
+ /* guard page */ PAGE_SIZE;
/* Free Remaining Sandbox Linear Address Space
* sandbox_size includes the struct and HTTP buffer
* The linear memory was already freed during the transition from running to error|complete
* struct sandbox | HTTP Buffer | 4GB of Wasm Linear Memory | Guard Page
* Allocated | Allocated | Freed | Freed
*/
/* Linear Memory and Guard Page should already have been munmaped and set to NULL */
assert(sandbox->linear_memory_start == NULL);
errno = 0;
rc = munmap(sandbox, sandbox_address_space_size);
rc = munmap(sandbox, sandbox->sandbox_size);
if (rc == -1) {
debuglog("Failed to unmap Sandbox %lu\n", sandbox->id);
goto err_free_sandbox_failed;

Loading…
Cancel
Save