Commit: 5ffa479a7573f04097b7b4ba7112da1e6dfda25b
Parent: ce1b97be1ecc16d0737955fd79918ce58f8351d4
Author: Randy Palamar
Date: Mon, 4 Nov 2024 08:44:13 -0700
hierarchical debug viewing
still some jank but it will be fixed soon
Diffstat:
M | debug.c | | | 74 | +++++++++++++++++++++++++++++++++++++++++++++++++------------------------- |
M | debug.h | | | 54 | ++++++++++++++++++++++++++++++------------------------ |
M | vtgl.c | | | 9 | ++++----- |
3 files changed, 83 insertions(+), 54 deletions(-)
diff --git a/debug.c b/debug.c
@@ -81,6 +81,8 @@ restart_collation(DebugState *ds, u32 invalid_record_index)
end_temp_arena(ds->temp_memory);
ds->temp_memory = begin_temp_arena(&ds->memory);
ds->first_free_block = 0;
+ /* TODO: no clear parameter */
+ ds->records = alloc(&ds->memory, typeof(*ds->records), 2*MAX_DEBUG_RECORD_COUNT);
ds->record_count = 0;
ds->record_bar_scale = 0;
ds->record_working_index = invalid_record_index + 1;
@@ -88,18 +90,19 @@ restart_collation(DebugState *ds, u32 invalid_record_index)
}
static void
-coalesce_debug_events(DebugState *ds, u32 invalid_snapshot_index, DebugMetadata *metadata)
+coalesce_debug_events(DebugState *ds, u32 invalid_snapshot_index)
{
BEGIN_TIMED_BLOCK();
for (;; ds->record_working_index++) {
- if (ds->record_working_index == DEBUG_SNAPSHOT_COUNT)
+ if (ds->record_working_index == MAX_DEBUG_RECORD_COUNT)
ds->record_working_index = 0;
if (ds->record_working_index == invalid_snapshot_index)
break;
u32 record_index = ds->record_working_index;
for (u32 j = 0; j < g_debug_table.events_count[record_index]; j++) {
- DebugEvent *de = g_debug_table.events[record_index] + j;
+ DebugEvent *de = g_debug_table.events[record_index] + j;
+ DebugMetadata *source_metadata = g_debug_table.metadata + de->metadata_index;
if (de->type == DE_FRAME_MARK) {
if (ds->open_record) {
@@ -113,27 +116,26 @@ coalesce_debug_events(DebugState *ds, u32 invalid_snapshot_index, DebugMetadata
ds->record_bar_scale = record_bar_scale;
}
ds->record_count++;
- if (ds->record_count >= DEBUG_SNAPSHOT_COUNT)
- /* TODO: is this just an error ? */
- goto end;
}
ds->open_record = ds->records + ds->record_count;
ds->open_record->start_clock = de->clock;
ds->open_record->end_clock = 0;
ds->open_record->region_count = 0;
ds->open_record->wall_time = 0;
- ds->open_record->first_block = get_open_debug_block(ds, 0);
+ ds->open_record->first_block = 0;
ds->open_record->regions = alloc(&ds->memory, DebugRegion,
MAX_DEBUG_REGION_COUNT);
} else if (ds->open_record) {
+ u32 frame_index = (ds->record_count - 1) % MAX_DEBUG_RECORD_COUNT;
DebugRecord *or = ds->open_record;
//ASSERT(or == ds->records + record_index);
//u64 relative_clock = de->clock - record->start_clock;
switch (de->type) {
case DE_BEGIN: {
OpenDebugBlock *odb = get_open_debug_block(ds, de);
- odb->starting_record_index = record_index;
+ odb->starting_record_index = frame_index;
odb->parent = or->first_block;
+ odb->source = source_metadata;
or->first_block = odb;
} break;
case DE_END: {
@@ -142,14 +144,15 @@ coalesce_debug_events(DebugState *ds, u32 invalid_snapshot_index, DebugMetadata
OpenDebugBlock *odb = or->first_block;
DebugEvent *oe = odb->opening_event;
- if (oe->debug_metadata_index != de->debug_metadata_index) {
+ if (oe->metadata_index != de->metadata_index) {
/* TODO: the first block was never closed */
INVALID_CODE_PATH;
break;
}
- if (odb->starting_record_index == record_index) {
- if (odb->parent->opening_event == 0) {
+ if (odb->starting_record_index == frame_index) {
+ DebugMetadata *source = odb->parent ? odb->parent->source : 0;
+ if (source == ds->selected_metadata) {
f32 min_t = (oe->clock - or->start_clock);
f32 max_t = (de->clock - or->start_clock);
if ((de->clock - oe->clock) > 1) {
@@ -157,7 +160,8 @@ coalesce_debug_events(DebugState *ds, u32 invalid_snapshot_index, DebugMetadata
ASSERT(or->region_count <= MAX_DEBUG_REGION_COUNT);
dr->min_t = min_t;
dr->max_t = max_t;
- dr->debug_metadata_index = de->debug_metadata_index;
+ dr->meta = source_metadata;
+ dr->colour_index = de->metadata_index;
}
}
} else {
@@ -175,11 +179,17 @@ coalesce_debug_events(DebugState *ds, u32 invalid_snapshot_index, DebugMetadata
}
}
-end:
END_TIMED_BLOCK();
}
static void
+refresh_collation(DebugState *ds)
+{
+ restart_collation(ds, g_debug_table.snapshot_index);
+ coalesce_debug_events(ds, g_debug_table.snapshot_index);
+}
+
+static void
draw_debug_bar_chart(Term *t, DebugState *ds, RenderCtx *rc, v2 bar_chart_top_left, f32 bar_chart_magnitude)
{
BEGIN_TIMED_BLOCK();
@@ -211,12 +221,16 @@ draw_debug_bar_chart(Term *t, DebugState *ds, RenderCtx *rc, v2 bar_chart_top_le
pos.y -= bar_thick + bar_pad;
- DebugMetadata *txt_meta = 0;
- f32 txt_secs = 0;
+ DebugRegion *hot_region = 0;
+ f32 hot_region_secs;
+
+ u32 displayed_records = ds->record_count;
+ if (displayed_records > 12)
+ displayed_records = 12;
Stream txt = stream_alloc(ds->temp_memory.arena, 1024);
- for (u32 i = 0; i < ds->record_count; i++) {
- DebugRecord *record = ds->records + i;
+ for (u32 i = 0; i < displayed_records; i++) {
+ DebugRecord *record = ds->records + (ds->record_count - (i + 1)) % MAX_DEBUG_RECORD_COUNT;
f32 cycs_to_secs = record->wall_time / (f32)(record->end_clock - record->start_clock);
f32 scale = cycs_to_secs * secs_scale;
@@ -227,10 +241,10 @@ draw_debug_bar_chart(Term *t, DebugState *ds, RenderCtx *rc, v2 bar_chart_top_le
f32 time = cycs * scale;
Rect r = {.pos = pos, .size = {.h = bar_thick, .w = time}};
if (r.size.w > 1.0f) {
- push_rect(rc, r, colours[dr->debug_metadata_index % ARRAY_COUNT(colours)]);
+ push_rect(rc, r, colours[dr->colour_index % ARRAY_COUNT(colours)]);
if (point_in_rect(mouse, r)) {
- txt_meta = debug_metadata + dr->debug_metadata_index;
- txt_secs = cycs * cycs_to_secs;
+ hot_region = dr;
+ hot_region_secs = cycs * cycs_to_secs;
}
pos.x += r.size.w;
}
@@ -250,21 +264,22 @@ draw_debug_bar_chart(Term *t, DebugState *ds, RenderCtx *rc, v2 bar_chart_top_le
Rect target_marker = {.pos = pos};
target_marker.pos.x += bar_chart_magnitude;
target_marker.size.w = 4;
- target_marker.size.h = ds->record_count * (bar_thick + bar_pad) - bar_pad;
- push_rect(rc, target_marker, colours[0]);
+ target_marker.size.h = displayed_records * (bar_thick + bar_pad) - bar_pad;
+ push_rect(rc, target_marker, (v4){.g = .38, .b = .78, .a = 1});
stream_push_s8(&txt, s8("Target Time: "));
stream_push_f64(&txt, target_time * 1e3, 100);
pos.x += bar_chart_magnitude + 8;
- pos.y = bar_chart_top_left.y - 0.5 * DEBUG_SNAPSHOT_COUNT * (bar_thick + bar_pad);
+ pos.y = bar_chart_top_left.y - 0.75 * displayed_records * (bar_thick + bar_pad);
stream_push_s8(&txt, s8(" [ms]"));
push_s8(rc, pos, fg, g_ui_debug_font_id, stream_to_s8(&txt));
- if (txt_meta) {
+ if (hot_region) {
+ DebugMetadata *txt_meta = hot_region->meta;
txt.widx = 0;
stream_push_s8(&txt, c_str_to_s8(txt_meta->function_name));
stream_push_s8(&txt, s8(": "));
- stream_push_f64(&txt, txt_secs * 1e3, 100);
+ stream_push_f64(&txt, hot_region_secs * 1e3, 100);
stream_push_s8(&txt, s8(" [ms] "));
stream_push_s8(&txt, c_str_to_s8(txt_meta->file_name));
stream_push_byte(&txt, ':');
@@ -272,6 +287,15 @@ draw_debug_bar_chart(Term *t, DebugState *ds, RenderCtx *rc, v2 bar_chart_top_le
push_s8(rc, mouse, fg, g_ui_debug_font_id, stream_to_s8(&txt));
}
+ /* TODO: this should be stored so that we can properly mask */
+ b32 pressed = glfwGetMouseButton(t->gl.window, GLFW_MOUSE_BUTTON_LEFT) == GLFW_PRESS;
+ if (pressed && pressed != ds->mouse_pressed_last_frame) {
+ if (hot_region) ds->selected_metadata = hot_region->meta;
+ else ds->selected_metadata = 0;
+ refresh_collation(ds);
+ }
+ ds->mouse_pressed_last_frame = pressed;
+
END_TIMED_BLOCK();
}
diff --git a/debug.h b/debug.h
@@ -3,17 +3,12 @@
#define MAX_DEBUG_EVENT_COUNT (16 * 65536)
/* TODO: this is way too high and it only seems to be necessary when resizing */
#define MAX_DEBUG_REGION_COUNT 80 * 1024
-#define DEBUG_SNAPSHOT_COUNT 16
-
-typedef struct {
- f32 min_t;
- f32 max_t;
- u16 debug_metadata_index;
-} DebugRegion;
+#define MAX_DEBUG_META_COUNT 4096
+#define MAX_DEBUG_RECORD_COUNT 16
typedef __attribute__((aligned(16))) struct {
u64 clock;
- u16 debug_metadata_index;
+ u16 metadata_index;
u16 type;
union {
/* TODO: store core + thread id if we make this multithreaded */
@@ -22,8 +17,23 @@ typedef __attribute__((aligned(16))) struct {
};
} DebugEvent;
+typedef struct {
+ char *file_name;
+ char *function_name;
+
+ u32 line_number;
+} DebugMetadata;
+
+typedef struct {
+ f32 min_t;
+ f32 max_t;
+ DebugMetadata *meta;
+ u16 colour_index;
+} DebugRegion;
+
typedef struct OpenDebugBlock {
DebugEvent *opening_event;
+ DebugMetadata *source;
struct OpenDebugBlock *parent;
struct OpenDebugBlock *next_free;
u32 starting_record_index;
@@ -51,9 +61,12 @@ typedef struct {
f32 gpu_target_time;
u32 frame_draw_count;
+ DebugMetadata *selected_metadata;
+ b32 mouse_pressed_last_frame;
+
u32 record_count;
u32 record_working_index;
- DebugRecord records[DEBUG_SNAPSHOT_COUNT];
+ DebugRecord *records;
DebugRecord *open_record;
OpenDebugBlock *first_free_block;
@@ -93,29 +106,22 @@ enum debug_event_types {
};
typedef struct {
- char *file_name;
- char *function_name;
-
- u32 line_number;
-} DebugMetadata;
-
-typedef struct {
- DebugEvent events[DEBUG_SNAPSHOT_COUNT][MAX_DEBUG_EVENT_COUNT];
- u32 events_count[DEBUG_SNAPSHOT_COUNT];
+ DebugEvent events[MAX_DEBUG_RECORD_COUNT][MAX_DEBUG_EVENT_COUNT];
+ u32 events_count[MAX_DEBUG_RECORD_COUNT];
u64 event_array_event_index;
+ DebugMetadata metadata[MAX_DEBUG_META_COUNT];
+ u32 metadata_count;
u32 snapshot_index;
} DebugTable;
static DebugTable g_debug_table;
-DebugMetadata debug_metadata[];
-
#define RECORD_DEBUG_EVENT_COMMON(counter, event_type) \
u64 event_index = __atomic_fetch_add(&g_debug_table.event_array_event_index, 1, __ATOMIC_RELAXED); \
ASSERT((event_index & 0xFFFFFFFF) < MAX_DEBUG_EVENT_COUNT); \
DebugEvent *event = g_debug_table.events[event_index >> 32] + (event_index & 0xFFFFFFFF); \
- event->clock = __rdtsc(); \
- event->debug_metadata_index = counter; \
- event->type = event_type
+ event->clock = __rdtsc(); \
+ event->metadata_index = counter; \
+ event->type = event_type
#define RECORD_DEBUG_EVENT(counter, event_type) \
{ \
@@ -131,7 +137,7 @@ DebugMetadata debug_metadata[];
#define BEGIN_TIMED_BLOCK(...) \
u16 __counter = __COUNTER__; \
{ \
- DebugMetadata *meta = debug_metadata + __counter; \
+ DebugMetadata *meta = g_debug_table.metadata + __counter; \
meta->file_name = __FILE__; \
meta->function_name = (char *)__FUNCTION__; \
meta->line_number = __LINE__; \
diff --git a/vtgl.c b/vtgl.c
@@ -925,12 +925,10 @@ end:
#ifdef _DEBUG
#include "debug.c"
-DebugMetadata debug_metadata[__COUNTER__];
-
DEBUG_EXPORT DEBUG_END_FRAME_FN(debug_end_frame)
{
g_debug_table.snapshot_index++;
- if (g_debug_table.snapshot_index == DEBUG_SNAPSHOT_COUNT)
+ if (g_debug_table.snapshot_index == MAX_DEBUG_RECORD_COUNT)
g_debug_table.snapshot_index = 0;
u64 event_array_event_index = __atomic_exchange_n(&g_debug_table.event_array_event_index,
(u64)g_debug_table.snapshot_index << 32,
@@ -940,6 +938,7 @@ DEBUG_EXPORT DEBUG_END_FRAME_FN(debug_end_frame)
u32 event_count = event_array_event_index & 0xFFFFFFFF;
g_debug_table.events_count[array_index] = event_count;
+ g_debug_table.metadata_count = __COUNTER__;
if (!debug_state->initialized) {
debug_state->temp_memory = begin_temp_arena(&debug_state->memory);
@@ -950,9 +949,9 @@ DEBUG_EXPORT DEBUG_END_FRAME_FN(debug_end_frame)
}
if (!debug_state->paused) {
- if (debug_state->record_count >= DEBUG_SNAPSHOT_COUNT)
+ if (debug_state->record_count >= 2*MAX_DEBUG_RECORD_COUNT)
restart_collation(debug_state, g_debug_table.snapshot_index);
- coalesce_debug_events(debug_state, g_debug_table.snapshot_index, debug_metadata);
+ coalesce_debug_events(debug_state, g_debug_table.snapshot_index);
}
}