vtgl

Commit: 1e9e8b6b04b22445caba3a0a9cc93cf31343c794
Parent: 4630eea3fcc6945743c7224635e0e10887a95720
Author: Randy Palamar
Date:   Fri, 18 Oct 2024 22:26:43 -0600

upgrade debug cycle counts by using __COUNTER__

single translation unit with this compiler macro is overpowered.
The debug overlay is subject to change but this already makes it
way easier to add new profiling info.

Diffstat:
M
debug.c
 | 
118
-------------------------------------------------------------------------------
M
debug.h
 | 
62
++++++++++++++++++++++++++++++++++++++------------------------
M
font.c
 | 
4
++--
M
main.c
 | 
5
+++++
M
terminal.c
 | 
8
++++----
M
vtgl.c
 | 
117
+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++-----

6 files changed, 160 insertions(+), 154 deletions(-)
diff --git a/debug.c b/debug.c
@@ -226,121 +226,3 @@ debug_draw_text(Term *t, RenderPushBuffer *rpb, s8 text, v2 position, Colour fg,
 		position.x += monospaced? single_space_width : g.size.w;
 	}
 }
-
-static void
-draw_debug_overlay(Term *t, RenderPushBuffer *rpb)
-{
-	static struct {
-		char *line1, *line2;
-	} fmts[CC_LAST] = {
-		[CC_RENDER_FRAMEBUFFER] = {.line1 = "Render FB:    %ld cyc | %d hit",
-		                           .line2 = "              %0.2f cyc/h\n"},
-		[CC_RENDER_GLYPH]       = {.line1 = "Render Glyph: %ld cyc | %d hit",
-		                           .line2 = "              %0.2f cyc/h\n"},
-		[CC_BLIT_LINES]         = {.line1 = "Blit Lines:   %ld cyc | %d hit",
-		                           .line2 = "              %0.2f cyc/h\n"},
-		[CC_SPLIT_LINES]        = {.line1 = "Split Lines:  %ld cyc | %d hit",
-		                           .line2 = "              %0.2f cyc/h\n"},
-	};
-
-	static i64 cycs[CC_LAST];
-	static i64 hits[CC_LAST];
-
-	for (u32 i = 0; i < CC_LAST; i++) {
-		if (g_debug_clock_counts.total_cycles[i] == 0)
-			continue;
-		cycs[i] = g_debug_clock_counts.total_cycles[i];
-		hits[i] = g_debug_clock_counts.hit_count[i];
-		g_debug_clock_counts.hit_count[i]  = 0;
-		g_debug_clock_counts.total_cycles[i] = 0;
-	}
-
-	if (!(t->gl.flags & DRAW_DEBUG_OVERLAY))
-		return;
-
-	glUniform1i(t->gl.render.texslot, 1);
-
-	v2 ws  = t->gl.window_size;
-	s8 buf = s8alloc(&t->arena_for_frame, 128);
-
-	static GlyphCacheStats glyph_stats;
-	static Rect r;
-	static f32 max_text_width;
-	r.pos.x  = ws.w - 1.1 * max_text_width;
-	r.size.x = 1.1 * max_text_width;
-
-	Colour fg = {.rgba = 0x1e9e33ff};
-	Colour bg = {.rgba = 0x222222ff};
-
-	draw_rectangle(rpb, &t->gl, r, bg);
-
-	f32 line_pad = 5;
-	v2 txt_pos = {.x = (u32)(r.pos.x + 5), .y = ws.h};
-
-	{
-		s8 txt    = buf;
-		txt.len   = snprintf((char *)txt.data, buf.len, "Render Time:  %0.02f ms/f", dt_for_frame * 1e3);
-		v2 ts     = debug_measure_text(t, &t->debug_font, txt, 1);
-		txt_pos.y = (u32)(txt_pos.y - ts.y - line_pad);
-		debug_draw_text(t, rpb, txt, txt_pos, fg, bg, 1);
-
-		if (ts.w > max_text_width) max_text_width = ts.w;
-	}
-
-	for (u32 i = 0; i < CC_LAST; i++) {
-		if (hits[i] == 0)
-			continue;
-		s8 txt = buf;
-		txt.len   = snprintf((char *)txt.data, buf.len, fmts[i].line1, cycs[i], hits[i]);
-		v2 ts     = debug_measure_text(t, &t->debug_font, txt, 1);
-		txt_pos.y = (u32)(txt_pos.y - ts.y - line_pad);
-		debug_draw_text(t, rpb, txt, txt_pos, fg, bg, 1);
-
-		if (ts.w > max_text_width) max_text_width = ts.w;
-
-		txt.len   = snprintf((char *)txt.data, buf.len, fmts[i].line2, (f32)cycs[i]/(f32)hits[i]);
-		ts        = debug_measure_text(t, &t->debug_font, txt, 1);
-		txt_pos.y = (u32)(txt_pos.y - ts.y - line_pad);
-		debug_draw_text(t, rpb, txt, txt_pos, fg, bg, 1);
-
-		if (ts.w > max_text_width) max_text_width = ts.w;
-	}
-
-	{
-		s8 txt    = buf;
-		txt.len   = snprintf((char *)txt.data, buf.len, "FB cyc/cell:  %0.02f",
-		                     cycs[CC_RENDER_FRAMEBUFFER] / (f32)(t->size.w * t->size.h));
-		v2 ts     = debug_measure_text(t, &t->debug_font, txt, 1);
-		txt_pos.y = (u32)(txt_pos.y - ts.y - line_pad);
-		debug_draw_text(t, rpb, txt, txt_pos, fg, bg, 1);
-
-		if (ts.w > max_text_width) max_text_width = ts.w;
-	}
-
-	GlyphCacheStats new_glyph_stats = get_and_clear_glyph_cache_stats(&t->fa.glyph_cache);
-	if (new_glyph_stats.hit_count != 0)
-		glyph_stats = new_glyph_stats;
-	{
-		v2 ts     = debug_measure_text(t, &t->debug_font, s8("Glyph Cache Stats:"), 1);
-		txt_pos.y = (u32)(txt_pos.y - ts.y - line_pad);
-		txt_pos.y = (u32)(txt_pos.y - ts.y - line_pad);
-		debug_draw_text(t, rpb, s8("Glyph Cache Stats:"), txt_pos, fg, bg, 1);
-
-		static char *fmts[ARRAY_COUNT(glyph_stats.E)] = {
-			"  Hits:     %u",
-			"  Misses:   %u",
-			"  Recycles: %u",
-		};
-		for (u32 i = 0; i < ARRAY_COUNT(glyph_stats.E); i++) {
-			s8 txt    = buf;
-			txt.len   = snprintf((char *)txt.data, buf.len, fmts[i], glyph_stats.E[i]);
-			ts        = debug_measure_text(t, &t->debug_font, txt, 1);
-			txt_pos.y = (u32)(txt_pos.y - ts.y - line_pad);
-			debug_draw_text(t, rpb, txt, txt_pos, fg, bg, 1);
-			if (ts.w > max_text_width) max_text_width = ts.w;
-		}
-	}
-
-	r.pos.y  = txt_pos.y - 2 * line_pad;
-	r.size.h = ws.h - r.pos.y;
-}
diff --git a/debug.h b/debug.h
@@ -2,35 +2,49 @@
 #define ASSERT(c) do { (void)(c); } while(0)
 #define DEBUG_EXPORT static
 
-#define BEGIN_CYCLE_COUNT(a)
-#define END_CYCLE_COUNT(a)
+#define BEGIN_TIMED_BLOCK(...)
+#define END_TIMED_BLOCK(...)
+
+#define debug_init(...)
+#define draw_debug_overlay(...)
 
 #else
 
 #define ASSERT(c) do { if (!(c)) asm("int3; nop"); } while(0)
 #define DEBUG_EXPORT
 
-/* NOTE: Performance Counters */
-enum clock_counts {
-	CC_RENDER_FRAMEBUFFER,
-	CC_RENDER_GLYPH,
-	CC_BLIT_LINES,
-	CC_SPLIT_LINES,
-	CC_LAST
-};
-
-static struct {
-	i64 cpu_cycles[CC_LAST];
-	i64 total_cycles[CC_LAST];
-	i64 hit_count[CC_LAST];
-} g_debug_clock_counts;
-
-#define BEGIN_CYCLE_COUNT(cc_name) \
-	g_debug_clock_counts.cpu_cycles[cc_name] = __rdtsc(); \
-	g_debug_clock_counts.hit_count[cc_name]++
-
-#define END_CYCLE_COUNT(cc_name) \
-	g_debug_clock_counts.cpu_cycles[cc_name] = __rdtsc() - g_debug_clock_counts.cpu_cycles[cc_name]; \
-	g_debug_clock_counts.total_cycles[cc_name] += g_debug_clock_counts.cpu_cycles[cc_name]
+typedef struct {
+	u64 cycles;
+
+	char *file_name;
+	char *function_name;
+
+	u32 line_number;
+	u32 hit_count;
+} DebugRecord;
+
+DebugRecord debug_records[];
+
+static u32
+begin_timed_block(u32 counter, char *file_name, char *function_name, i32 line_number)
+{
+	DebugRecord *record    = debug_records + counter;
+	record->cycles        -= __rdtsc();
+	record->file_name      = file_name;
+	record->function_name  = function_name;
+	record->line_number    = line_number;
+	record->hit_count     += 1;
+	return counter;
+}
+
+static void
+end_timed_block(u32 counter)
+{
+	DebugRecord *record  = debug_records + counter;
+	record->cycles      += __rdtsc();
+}
+
+#define BEGIN_TIMED_BLOCK(...) u32 __counter = begin_timed_block(__COUNTER__, __FILE__, (char *)__FUNCTION__, __LINE__)
+#define END_TIMED_BLOCK(...) end_timed_block(__counter)
 
 #endif
diff --git a/font.c b/font.c
@@ -122,7 +122,7 @@ get_and_clear_glyph_cache_stats(GlyphCache *gc)
 static u32 *
 render_glyph(Arena *a, FontAtlas *fa, u32 cp, enum face_style style, CachedGlyph **out_glyph, u32 *out_idx)
 {
-	BEGIN_CYCLE_COUNT(CC_RENDER_GLYPH);
+	BEGIN_TIMED_BLOCK();
 	u32 *rgba_bitmap = NULL;
 
 	/* NOTE: first check if glyph is in the cache and valid */
@@ -182,7 +182,7 @@ render_glyph(Arena *a, FontAtlas *fa, u32 cp, enum face_style style, CachedGlyph
 	if (cp == ' ') cg->g.size.w = fa->info.w;
 
 end:
-	END_CYCLE_COUNT(CC_RENDER_GLYPH);
+	END_TIMED_BLOCK();
 
 	return rgba_bitmap;
 }
diff --git a/main.c b/main.c
@@ -368,3 +368,8 @@ main(i32 argc, char *argv[])
 
 	return 0;
 }
+
+#ifdef _DEBUG
+/* NOTE: shut up compiler warning that can't be disabled */
+DebugRecord debug_records[__COUNTER__];
+#endif
diff --git a/terminal.c b/terminal.c
@@ -1059,7 +1059,7 @@ check_if_escape_moves_cursor(Term *t, s8 *raw)
 static size
 split_raw_input_to_lines(Term *t, s8 raw)
 {
-	BEGIN_CYCLE_COUNT(CC_SPLIT_LINES);
+	BEGIN_TIMED_BLOCK();
 
 	TermView *tv = t->views + t->view_idx;
 	size parsed_lines = 0;
@@ -1154,7 +1154,7 @@ split_raw_input_to_lines(Term *t, s8 raw)
 	t->unprocessed_bytes = 0;
 
 end:
-	END_CYCLE_COUNT(CC_SPLIT_LINES);
+	END_TIMED_BLOCK();
 
 	return parsed_lines;
 }
@@ -1243,7 +1243,7 @@ get_line_idx(LineBuf *lb, size off)
 static void
 blit_lines(Term *t, Arena a, size line_count)
 {
-	BEGIN_CYCLE_COUNT(CC_BLIT_LINES);
+	BEGIN_TIMED_BLOCK();
 
 	TermView *tv = t->views + t->view_idx;
 
@@ -1267,5 +1267,5 @@ blit_lines(Term *t, Arena a, size line_count)
 
 	t->gl.flags &= ~(NEEDS_FULL_REFILL|NEEDS_REFILL);
 
-	END_CYCLE_COUNT(CC_BLIT_LINES);
+	END_TIMED_BLOCK();
 }
diff --git a/vtgl.c b/vtgl.c
@@ -9,11 +9,10 @@
 
 #include "font.c"
 #include "terminal.c"
+
 #ifdef _DEBUG
 #include "debug.c"
-#else
-#define debug_init(...)
-#define draw_debug_overlay(...)
+static void draw_debug_overlay(Term *, RenderPushBuffer *);
 #endif
 
 #define REVERSE_VIDEO_MASK (Colour){.r = 0xff, .g = 0xff, .b = 0xff}.rgba
@@ -243,6 +242,7 @@ draw_rectangle(RenderPushBuffer *rpb, GLCtx *gl, Rect r, Colour colour)
 static void
 push_cell(RenderPushBuffer *rpb, GLCtx *gl, Arena a, FontAtlas *fa, Cell c, Rect r, v2 cell_font_delta)
 {
+	BEGIN_TIMED_BLOCK();
 	u32 idx = get_render_push_buffer_idx(rpb, gl, 2);
 
 	ASSERT(c.cp);
@@ -278,6 +278,7 @@ push_cell(RenderPushBuffer *rpb, GLCtx *gl, Arena a, FontAtlas *fa, Cell c, Rect
 	rpb->texcolours[idx + 0].y = bg ^ rmask;
 	rpb->texcolours[idx + 1].x = fg ^ rmask;
 	rpb->texcolours[idx + 1].y = bg ^ rmask;
+	END_TIMED_BLOCK();
 }
 
 static void
@@ -306,7 +307,7 @@ push_cell_row(RenderPushBuffer *rpb, GLCtx *gl, Arena a, FontAtlas *fa, Cell *ro
 static void
 render_framebuffer(Term *t, RenderPushBuffer *rpb)
 {
-	BEGIN_CYCLE_COUNT(CC_RENDER_FRAMEBUFFER);
+	BEGIN_TIMED_BLOCK();
 
 	v2 tl   = get_terminal_top_left(t);
 	v2 cs   = get_cell_size(t);
@@ -359,7 +360,7 @@ render_framebuffer(Term *t, RenderPushBuffer *rpb)
 		push_cell(rpb, &t->gl, t->arena_for_frame, &t->fa, cursor, cr, cell_font_delta);
 	}
 
-	END_CYCLE_COUNT(CC_RENDER_FRAMEBUFFER);
+	END_TIMED_BLOCK();
 }
 
 static iv2
@@ -598,7 +599,6 @@ key_callback(GLFWwindow *win, i32 key, i32 sc, i32 act, i32 mods)
 		}
 	}
 
-
 	switch (ENCODE_KEY(act, 0, key)) {
 	case ENCODE_KEY(GLFW_PRESS,  0, GLFW_KEY_ESCAPE):
 	case ENCODE_KEY(GLFW_REPEAT, 0, GLFW_KEY_ESCAPE):
@@ -840,3 +840,108 @@ do_terminal(Term *t, f32 dt)
 	glUniform2fv(t->gl.post.vertscale, 1, ws.E);
 	glDrawArrays(GL_TRIANGLE_STRIP, 0, 4);
 }
+
+#ifdef _DEBUG
+DebugRecord debug_records[__COUNTER__];
+
+static void
+draw_debug_overlay(Term *t, RenderPushBuffer *rpb)
+{
+	static u64 cycs[ARRAY_COUNT(debug_records)];
+	static u32 hits[ARRAY_COUNT(debug_records)];
+
+	for (u32 i = 0; i < ARRAY_COUNT(debug_records); i++) {
+		DebugRecord *dr = debug_records + i;
+		if (dr->cycles == 0)
+			continue;
+		cycs[i]       = dr->cycles;
+		hits[i]       = dr->hit_count;
+		dr->hit_count = 0;
+		dr->cycles    = 0;
+	}
+
+	if (!(t->gl.flags & DRAW_DEBUG_OVERLAY))
+		return;
+
+	glUniform1i(t->gl.render.texslot, 1);
+
+	v2 ws  = t->gl.window_size;
+	s8 buf = s8alloc(&t->arena_for_frame, 128);
+
+	static GlyphCacheStats glyph_stats;
+	static Rect r;
+	static f32 max_text_width;
+	r.pos.x  = ws.w - 1.1 * max_text_width;
+	r.size.x = 1.1 * max_text_width;
+
+	Colour fg = {.rgba = 0x1e9e33ff};
+	Colour bg = {.rgba = 0x222222ff};
+
+	draw_rectangle(rpb, &t->gl, r, bg);
+
+	f32 line_pad = 5;
+	v2 txt_pos = {.x = (u32)(r.pos.x + 5), .y = ws.h};
+
+	{
+		s8 txt    = buf;
+		txt.len   = snprintf((char *)txt.data, buf.len, "Render Time:  %0.02f ms/f", dt_for_frame * 1e3);
+		v2 ts     = debug_measure_text(t, &t->debug_font, txt, 1);
+		txt_pos.y = (u32)(txt_pos.y - ts.y - line_pad);
+		debug_draw_text(t, rpb, txt, txt_pos, fg, bg, 1);
+
+		if (ts.w > max_text_width) max_text_width = ts.w;
+	}
+
+	for (u32 i = 0; i < ARRAY_COUNT(debug_records); i++) {
+		if (hits[i] == 0)
+			continue;
+
+		DebugRecord *dr = debug_records + i;
+
+		s8 txt = buf;
+		txt.len   = snprintf((char *)txt.data, buf.len, "%s: %u %s", dr->function_name,
+		                     hits[i], hits[i] > 1? "hits" : "hit");
+		v2 ts     = debug_measure_text(t, &t->debug_font, txt, 1);
+		txt_pos.y = (u32)(txt_pos.y - ts.y - line_pad);
+		debug_draw_text(t, rpb, txt, txt_pos, fg, bg, 1);
+
+		if (ts.w > max_text_width) max_text_width = ts.w;
+
+		txt.len   = snprintf((char *)txt.data, buf.len, "  %0.02f cycs/hit",
+		                     (f32)cycs[i]/(f32)hits[i]);
+		ts        = debug_measure_text(t, &t->debug_font, txt, 1);
+		txt_pos.y = (u32)(txt_pos.y - ts.y - line_pad);
+		debug_draw_text(t, rpb, txt, txt_pos, fg, bg, 1);
+
+		if (ts.w > max_text_width) max_text_width = ts.w;
+	}
+
+	GlyphCacheStats new_glyph_stats = get_and_clear_glyph_cache_stats(&t->fa.glyph_cache);
+	if (new_glyph_stats.hit_count != 0)
+		glyph_stats = new_glyph_stats;
+	{
+		v2 ts     = debug_measure_text(t, &t->debug_font, s8("Glyph Cache Stats:"), 1);
+		txt_pos.y = (u32)(txt_pos.y - ts.y - line_pad);
+		txt_pos.y = (u32)(txt_pos.y - ts.y - line_pad);
+		debug_draw_text(t, rpb, s8("Glyph Cache Stats:"), txt_pos, fg, bg, 1);
+
+		/* TODO: This doesn't really work when we are redrawing on every frame */
+		static char *fmts[ARRAY_COUNT(glyph_stats.E)] = {
+			"  Hits:     %u",
+			"  Misses:   %u",
+			"  Recycles: %u",
+		};
+		for (u32 i = 0; i < ARRAY_COUNT(glyph_stats.E); i++) {
+			s8 txt    = buf;
+			txt.len   = snprintf((char *)txt.data, buf.len, fmts[i], glyph_stats.E[i]);
+			ts        = debug_measure_text(t, &t->debug_font, txt, 1);
+			txt_pos.y = (u32)(txt_pos.y - ts.y - line_pad);
+			debug_draw_text(t, rpb, txt, txt_pos, fg, bg, 1);
+			if (ts.w > max_text_width) max_text_width = ts.w;
+		}
+	}
+
+	r.pos.y  = txt_pos.y - 2 * line_pad;
+	r.size.h = ws.h - r.pos.y;
+}
+#endif