feat: track longest held lock

main
Sean McBride 4 years ago
parent 63ca27ab7f
commit e83d79831f

@ -3,6 +3,7 @@
#include <stdint.h> #include <stdint.h>
extern __thread uint64_t generic_thread_lock_duration; extern __thread uint64_t generic_thread_lock_duration;
extern __thread uint64_t generic_thread_lock_longest;
extern __thread uint64_t generic_thread_start_timestamp; extern __thread uint64_t generic_thread_start_timestamp;
void generic_thread_dump_lock_overhead(); void generic_thread_dump_lock_overhead();

@ -1,6 +1,7 @@
#pragma once #pragma once
#include <spinlock/mcs.h> #include <spinlock/mcs.h>
#include <stdint.h>
#include "arch/getcycles.h" #include "arch/getcycles.h"
#include "runtime.h" #include "runtime.h"
@ -27,12 +28,17 @@ typedef ck_spinlock_mcs_t lock_t;
* @param lock - the address of the lock * @param lock - the address of the lock
* @param unique_variable_name - a unique prefix to hygienically namespace an associated lock/unlock pair * @param unique_variable_name - a unique prefix to hygienically namespace an associated lock/unlock pair
*/ */
#define LOCK_LOCK_WITH_BOOKKEEPING(lock, unique_variable_name) \ #define LOCK_LOCK_WITH_BOOKKEEPING(lock, unique_variable_name) \
assert(listener_thread_is_running() || !software_interrupt_is_enabled()); \ assert(listener_thread_is_running() || !software_interrupt_is_enabled()); \
struct ck_spinlock_mcs _hygiene_##unique_variable_name##_node; \ struct ck_spinlock_mcs _hygiene_##unique_variable_name##_node; \
uint64_t _hygiene_##unique_variable_name##_pre = __getcycles(); \ uint64_t _hygiene_##unique_variable_name##_pre = __getcycles(); \
ck_spinlock_mcs_lock((lock), &(_hygiene_##unique_variable_name##_node)); \ ck_spinlock_mcs_lock((lock), &(_hygiene_##unique_variable_name##_node)); \
generic_thread_lock_duration += (__getcycles() - _hygiene_##unique_variable_name##_pre); uint64_t _hygiene_##unique_variable_name##_duration = (__getcycles() - _hygiene_##unique_variable_name##_pre); \
if (_hygiene_##unique_variable_name##_duration > generic_thread_lock_longest) { \
generic_thread_lock_longest = _hygiene_##unique_variable_name##_duration; \
} \
generic_thread_lock_duration += _hygiene_##unique_variable_name##_duration;
/** /**
* Unlocks a lock * Unlocks a lock

@ -6,12 +6,14 @@
/* Implemented by listener and workers */ /* Implemented by listener and workers */
__thread uint64_t generic_thread_lock_duration = 0; __thread uint64_t generic_thread_lock_duration = 0;
__thread uint64_t generic_thread_lock_longest = 0;
__thread uint64_t generic_thread_start_timestamp = 0; __thread uint64_t generic_thread_start_timestamp = 0;
void void
generic_thread_initialize() generic_thread_initialize()
{ {
generic_thread_start_timestamp = __getcycles(); generic_thread_start_timestamp = __getcycles();
generic_thread_lock_longest = 0;
generic_thread_lock_duration = 0; generic_thread_lock_duration = 0;
} }
@ -26,6 +28,8 @@ generic_thread_dump_lock_overhead()
uint64_t duration = __getcycles() - generic_thread_start_timestamp; uint64_t duration = __getcycles() - generic_thread_start_timestamp;
debuglog("Locks consumed %lu / %lu cycles, or %f%%\n", generic_thread_lock_duration, duration, debuglog("Locks consumed %lu / %lu cycles, or %f%%\n", generic_thread_lock_duration, duration,
(double)generic_thread_lock_duration / duration * 100); (double)generic_thread_lock_duration / duration * 100);
debuglog("Longest Held Lock was %lu cycles, or %f quantums\n", generic_thread_lock_longest,
(double)generic_thread_lock_longest / ((uint64_t)runtime_processor_speed_MHz * runtime_quantum_us));
#endif #endif
#endif #endif
} }

Loading…
Cancel
Save