diff --git a/runtime/Makefile b/runtime/Makefile index 4ab5cbf..0e23dfb 100644 --- a/runtime/Makefile +++ b/runtime/Makefile @@ -14,22 +14,22 @@ BINARY_NAME=sledgert # Options: {USE_MEM_GENERIC, USE_MEM_VM} USE_MEM = USE_MEM_VM +# Feature Toggles +# CFLAGS += -DADMISSIONS_CONTROL + # Debugging Flags -# Strips out calls to assert() +# Strips out calls to assert() and disables debuglog # CFLAGS += -DNDEBUG -# Turns on debuglog and other assorted printfs in third party libs -CFLAGS += -DDEBUG - -# Redirects debuglogs to /runtime/bin/awesome.log -#FIXME This log should be changed to sledge.log (and likely to a user defined path) +# Redirects debuglogs to /runtime/bin/sledge.log # CFLAGS += -DLOG_TO_FILE # Various Informational Logs for Debugging # CFLAGS += -DLOG_HTTP_PARSER # CFLAGS += -DLOG_STATE_CHANGES # CFLAGS += -DLOG_LOCK_OVERHEAD +# CFLAGS += -DLOG_LISTENER_LOCK_OVERHEAD # CFLAGS += -DLOG_CONTEXT_SWITCHES # CFLAGS += -DLOG_ADMISSIONS_CONTROL # CFLAGS += -DLOG_REQUEST_ALLOCATION @@ -38,13 +38,13 @@ CFLAGS += -DDEBUG # This flag dumps totals of incoming requests and outgoing responses, broken out by status code # family, such as 2XX, 4XX, 5XX. It is useful to debug clients hanging waiting for a response. -# To log, run `call runtime_log_requests_responses()` while in GDB +# To log, run `call http_total_log()` while in GDB # CFLAGS += -DLOG_TOTAL_REQS_RESPS # This flag logs the total number of sandboxes in the various states # It is useful to debug if sandboxes are "getting caught" in a particular state # To log, run `call runtime_log_sandbox_states()` while in GDB -# CFLAGS += -DLOG_SANDBOX_TOTALS +# CFLAGS += -DLOG_SANDBOX_COUNT # This flag enables an per-worker atomic count of sandbox's local runqueue count in thread local storage # Useful to debug if sandboxes are "getting caught" or "leaking" while in a local runqueue diff --git a/runtime/src/runtime.c b/runtime/src/runtime.c index 28a63f9..8b4fe87 100644 --- a/runtime/src/runtime.c +++ b/runtime/src/runtime.c @@ -64,6 +64,25 @@ runtime_initialize(void) * Listener Thread Logic * ************************/ +static inline void +listener_thread_start_lock_overhead_measurement(uint64_t request_arrival_timestamp) +{ +#ifdef LOG_LISTENER_LOCK_OVERHEAD + worker_thread_start_timestamp = request_arrival_timestamp; + worker_thread_lock_duration = 0; +#endif +} + +static inline void +listener_thread_stop_lock_overhead_measurement() +{ +#ifdef LOG_LISTENER_LOCK_OVERHEAD + uint64_t worker_duration = __getcycles() - worker_thread_start_timestamp; + debuglog("Locks consumed %lu / %lu cycles, or %f%%\n", worker_thread_lock_duration, worker_duration, + (double)worker_thread_lock_duration / worker_duration * 100); +#endif +} + /** * @brief Execution Loop of the listener core, io_handles HTTP requests, allocates sandbox request objects, and pushes * the sandbox object to the global dequeue @@ -95,6 +114,7 @@ listener_thread_main(void *dummy) assert(descriptor_count > 0); uint64_t request_arrival_timestamp = __getcycles(); + listener_thread_start_lock_overhead_measurement(request_arrival_timestamp); for (int i = 0; i < descriptor_count; i++) { /* Check Event to determine if epoll returned an error */ if ((epoll_events[i].events & EPOLLERR) == EPOLLERR) { @@ -175,7 +195,8 @@ listener_thread_main(void *dummy) } /* while true */ } /* for loop */ - } /* while true */ + listener_thread_stop_lock_overhead_measurement(); + } /* while true */ panic("Listener thread unexpectedly broke loop\n");