debug.c (13997B)
1 static void 2 dump_lines_to_file(Term *t) 3 { 4 u8 buf[256]; 5 Stream fname = {.cap = sizeof(buf), .buf = buf}; 6 u64 current_time = os_get_time(); 7 stream_push_u64(&fname, current_time); 8 stream_push_s8(&fname, s8("-lines.bin\0")); 9 10 /* TODO: just replace this with some giant buffer, this is debug code */ 11 iptr file = os_open(buf, FA_WRITE); 12 if (file == INVALID_FILE) return; 13 14 fname.buf[fname.widx - 1] = '\n'; 15 os_write_err_msg(s8("dumping lines to ")); 16 os_write_err_msg(stream_to_s8(&fname)); 17 18 TermView *tv = t->views + t->view_idx; 19 size line_count = MIN(256, tv->lines.filled); 20 21 Arena temp_arena = t->arena_for_frame; 22 Stream out = stream_alloc(&temp_arena, MB(1)); 23 24 iv2 tsize = {.w = t->size.w, .h = t->size.h}; 25 iv2 wsize = {.w = t->gl.window_size.w, .h = t->gl.window_size.h}; 26 stream_push_s8(&out, s8("Term Info:")); 27 stream_push_s8(&out, s8("\n Size: ")); stream_push_iv2(&out, tsize); 28 stream_push_s8(&out, s8("\n Window Size: ")); stream_push_iv2(&out, wsize); 29 stream_push_s8(&out, s8("\n Mode: 0x")); stream_push_hex_u64(&out, t->mode.term); 30 stream_push_s8(&out, s8("\n Window Mode: 0x")); stream_push_hex_u64(&out, t->mode.win); 31 stream_push_s8(&out, s8("\n Scroll Region:")); 32 stream_push_s8(&out, s8("\n Top: ")); stream_push_u64(&out, t->top); 33 stream_push_s8(&out, s8("\n Bottom: ")); stream_push_u64(&out, t->bot); 34 stream_push_s8(&out, s8("\n Offset: ")); stream_push_i64(&out, t->scroll_offset); 35 stream_push_s8(&out, s8("\nRaw Line Count: ")); stream_push_u64(&out, (u32)line_count); 36 stream_push_s8(&out, s8("\n==============================\n")); 37 38 size file_offset = 0; 39 for (size i = -(line_count - 1); i <= 0; i++) { 40 Line *line = tv->lines.buf + get_line_idx(&tv->lines, i); 41 s8 l = line_to_s8(line, &tv->log); 42 stream_push_s8(&out, l); 43 if (out.errors) { 44 /* TODO: cleanup */ 45 os_offset_write(file, stream_to_s8(&out), file_offset); 46 file_offset += out.widx; 47 out.widx = 0; 48 stream_push_s8(&out, l); 49 } 50 } 51 stream_push_byte(&out, '\n'); 52 53 /* TODO: cleanup */ 54 os_offset_write(file, stream_to_s8(&out), file_offset); 55 os_close(file); 56 } 57 58 static OpenDebugBlock * 59 get_open_debug_block(DebugState *ds, DebugEvent *de) 60 { 61 OpenDebugBlock *result = ds->first_free_block; 62 if (result) { 63 ds->first_free_block = result->next_free; 64 } else { 65 result = alloc(ds->temp_memory.arena, OpenDebugBlock, 1); 66 } 67 result->next_free = 0; 68 result->parent = 0; 69 result->opening_event = de; 70 return result; 71 } 72 73 static void 74 restart_collation(DebugState *ds, u32 invalid_record_index) 75 { 76 end_temp_arena(ds->temp_memory); 77 ds->temp_memory = begin_temp_arena(&ds->memory); 78 ds->first_free_block = 0; 79 /* TODO: no clear parameter */ 80 ds->records = alloc(&ds->memory, typeof(*ds->records), 2*MAX_DEBUG_RECORD_COUNT); 81 ds->record_count = 0; 82 ds->record_bar_scale = 0; 83 ds->record_working_index = invalid_record_index + 1; 84 ds->open_record = 0; 85 } 86 87 static void 88 coalesce_debug_events(DebugState *ds, u32 invalid_snapshot_index) 89 { 90 BEGIN_TIMED_BLOCK(); 91 92 for (;; ds->record_working_index++) { 93 if (ds->record_working_index == MAX_DEBUG_RECORD_COUNT) 94 ds->record_working_index = 0; 95 if (ds->record_working_index == invalid_snapshot_index) 96 break; 97 u32 record_index = ds->record_working_index; 98 for (u32 j = 0; j < g_debug_table.events_count[record_index]; j++) { 99 DebugEvent *de = g_debug_table.events[record_index] + j; 100 DebugMetadata *source_metadata = g_debug_table.metadata + de->metadata_index; 101 102 if (de->type == DE_FRAME_MARK) { 103 if (ds->open_record) { 104 DebugRecord *or = ds->open_record; 105 or->end_clock = de->clock; 106 or->wall_time = de->wall_clock_time; 107 f32 elapsed_time = or->end_clock - or->start_clock; 108 if (elapsed_time) { 109 f32 record_bar_scale = 1 / elapsed_time; 110 if (record_bar_scale > ds->record_bar_scale) 111 ds->record_bar_scale = record_bar_scale; 112 } 113 ds->record_count++; 114 } 115 ds->open_record = ds->records + ds->record_count; 116 ds->open_record->start_clock = de->clock; 117 ds->open_record->end_clock = 0; 118 ds->open_record->region_count = 0; 119 ds->open_record->wall_time = 0; 120 ds->open_record->first_block = 0; 121 ds->open_record->regions = alloc(&ds->memory, DebugRegion, 122 MAX_DEBUG_REGION_COUNT); 123 } else if (ds->open_record) { 124 u32 frame_index = (ds->record_count - 1) % MAX_DEBUG_RECORD_COUNT; 125 DebugRecord *or = ds->open_record; 126 //ASSERT(or == ds->records + record_index); 127 //u64 relative_clock = de->clock - record->start_clock; 128 switch (de->type) { 129 case DE_BEGIN: { 130 OpenDebugBlock *odb = get_open_debug_block(ds, de); 131 odb->starting_record_index = frame_index; 132 odb->parent = or->first_block; 133 odb->source = source_metadata; 134 or->first_block = odb; 135 } break; 136 case DE_END: { 137 if (!or->first_block) 138 break; 139 140 OpenDebugBlock *odb = or->first_block; 141 DebugEvent *oe = odb->opening_event; 142 if (oe->metadata_index != de->metadata_index) { 143 /* TODO: the first block was never closed */ 144 //INVALID_CODE_PATH; 145 break; 146 } 147 148 if (odb->starting_record_index == frame_index) { 149 DebugMetadata *source = odb->parent ? odb->parent->source : 0; 150 if (source == ds->selected_metadata) { 151 f32 min_t = (oe->clock - or->start_clock); 152 f32 max_t = (de->clock - or->start_clock); 153 if ((de->clock - oe->clock) > 1) { 154 DebugRegion *dr = or->regions + or->region_count++; 155 ASSERT(or->region_count <= MAX_DEBUG_REGION_COUNT); 156 dr->min_t = min_t; 157 dr->max_t = max_t; 158 dr->meta = source_metadata; 159 dr->colour_index = de->metadata_index; 160 } 161 } 162 } else { 163 /* TODO: this record spans multiple running frames; 164 * need to record all enclosing events */ 165 INVALID_CODE_PATH; 166 } 167 odb->next_free = ds->first_free_block; 168 or->first_block = odb->parent; 169 ds->first_free_block = odb; 170 } break; 171 default: INVALID_CODE_PATH; 172 } 173 } 174 } 175 } 176 177 END_TIMED_BLOCK(); 178 } 179 180 static void 181 refresh_collation(DebugState *ds) 182 { 183 restart_collation(ds, g_debug_table.snapshot_index); 184 coalesce_debug_events(ds, g_debug_table.snapshot_index); 185 } 186 187 static void 188 draw_debug_bar_chart(Term *t, DebugState *ds, TerminalInput *input, RenderCtx *rc, 189 v2 bar_chart_top_left, f32 bar_chart_magnitude) 190 { 191 BEGIN_TIMED_BLOCK(); 192 193 f32 bar_thick = ds->bar_thickness; 194 f32 bar_pad = 0.5 * ds->bar_thickness; 195 v2 pos = bar_chart_top_left; 196 f32 target_time = ds->frame_target_time; 197 f32 secs_scale = bar_chart_magnitude / ds->frame_target_time; 198 199 /* TODO */ 200 v4 fg = normalize_colour((Colour){.rgba = 0x1e9e33ff}); 201 v4 colours[] = { 202 (v4){.r = 0.5, .g = 0.0, .b = 0.0, .a = 1.0}, 203 (v4){.r = 0.0, .g = 0.5, .b = 0.0, .a = 1.0}, 204 (v4){.r = 0.0, .g = 0.0, .b = 0.5, .a = 1.0}, 205 (v4){.r = 0.5, .g = 0.5, .b = 0.0, .a = 1.0}, 206 (v4){.r = 0.5, .g = 0.0, .b = 0.5, .a = 1.0}, 207 (v4){.r = 0.0, .g = 0.5, .b = 0.5, .a = 1.0}, 208 }; 209 210 pos.y -= bar_thick + bar_pad; 211 212 DebugRegion *hot_region = 0; 213 f32 hot_region_secs = 0; 214 215 u32 displayed_records = ds->record_count; 216 if (displayed_records > 12) 217 displayed_records = 12; 218 219 Stream txt = stream_alloc(ds->temp_memory.arena, 1024); 220 for (u32 i = 0; i < displayed_records; i++) { 221 DebugRecord *record = ds->records + (ds->record_count - (i + 1)) % MAX_DEBUG_RECORD_COUNT; 222 223 f32 cycs_to_secs = record->wall_time / (f32)(record->end_clock - record->start_clock); 224 f32 scale = cycs_to_secs * secs_scale; 225 pos.y -= bar_thick + bar_pad; 226 for (u32 j = 0; j < record->region_count; j++) { 227 DebugRegion *dr = record->regions + j; 228 f32 cycs = dr->max_t - dr->min_t; 229 f32 time = cycs * scale; 230 Rect r = {.pos = pos, .size = {.h = bar_thick, .w = time}}; 231 if (r.size.w > 1.0f) { 232 push_rect(rc, r, colours[dr->colour_index % ARRAY_COUNT(colours)]); 233 if (point_in_rect(input->mouse, r)) { 234 hot_region = dr; 235 hot_region_secs = cycs * cycs_to_secs; 236 /* TODO: actually use the interaction system; for now we 237 * just mask to prevent selection behind debug overlay */ 238 t->interaction.hot.type = IS_DEBUG; 239 } 240 pos.x += r.size.w; 241 } 242 } 243 pos.x = bar_chart_top_left.x; 244 //stream_push_f64(&txt, record->wall_time * 1e3, 100); 245 //stream_push_s8(&txt, s8(" [ms]")); 246 stream_push_u64(&txt, record->end_clock - record->start_clock); 247 stream_push_s8(&txt, s8(" [cycs]")); 248 v2 txt_s = measure_text(rc, g_ui_debug_font_id, stream_to_s8(&txt)); 249 v2 txt_p = {.x = pos.x - txt_s.w - 10, .y = pos.y}; 250 push_s8(rc, txt_p, fg, g_ui_debug_font_id, stream_to_s8(&txt)); 251 txt.widx = 0; 252 } 253 254 v4 target_colour = (v4){.g = .38, .b = .78, .a = 1}; 255 Rect target_marker = {.pos = pos}; 256 target_marker.pos.x += bar_chart_magnitude; 257 target_marker.size.w = 4; 258 target_marker.size.h = displayed_records * (bar_thick + bar_pad) - bar_pad; 259 push_rect(rc, target_marker, target_colour); 260 261 stream_push_s8(&txt, s8("Target Time: ")); 262 stream_push_f64(&txt, target_time * 1e3, 100); 263 pos.x += bar_chart_magnitude + 8; 264 pos.y = bar_chart_top_left.y - 0.75 * displayed_records * (bar_thick + bar_pad); 265 stream_push_s8(&txt, s8(" [ms]")); 266 push_s8(rc, pos, target_colour, g_ui_debug_font_id, stream_to_s8(&txt)); 267 268 if (hot_region) { 269 DebugMetadata *txt_meta = hot_region->meta; 270 txt.widx = 0; 271 stream_push_s8(&txt, c_str_to_s8(txt_meta->block_name)); 272 stream_push_s8(&txt, s8(": ")); 273 stream_push_f64(&txt, hot_region_secs * 1e3, 100); 274 stream_push_s8(&txt, s8(" [ms] ")); 275 stream_push_s8(&txt, c_str_to_s8(txt_meta->file_name)); 276 stream_push_byte(&txt, ':'); 277 stream_push_u64(&txt, txt_meta->line_number); 278 push_s8(rc, input->mouse, fg, g_ui_debug_font_id, stream_to_s8(&txt)); 279 } 280 281 ButtonState *mouse_left = input->keys + MOUSE_LEFT; 282 if (mouse_left->ended_down && mouse_left->transitions > 0) { 283 if (hot_region) ds->selected_metadata = hot_region->meta; 284 else ds->selected_metadata = 0; 285 refresh_collation(ds); 286 } 287 288 END_TIMED_BLOCK(); 289 } 290 291 static void 292 draw_debug_overlay(TerminalMemory *term_memory, TerminalInput *input, RenderCtx *rc) 293 { 294 Term *t = term_memory->memory; 295 DebugState *ds = term_memory->debug_memory; 296 297 if (!(t->gl.flags & DRAW_DEBUG_OVERLAY)) 298 return; 299 300 BEGIN_TIMED_BLOCK(); 301 302 v2 bar_chart_top_left = v2_from_iv2(t->gl.window_size); 303 bar_chart_top_left.x *= 0.5; 304 draw_debug_bar_chart(t, ds, input, rc, bar_chart_top_left, 0.25 * t->gl.window_size.w); 305 306 Arena memory = *ds->temp_memory.arena; 307 308 v2 ws = v2_from_iv2(t->gl.window_size); 309 310 static GlyphCacheStats glyph_stats; 311 static Rect r; 312 static f32 max_text_width; 313 static f32 line_height; 314 r.pos.x = ws.w - (max_text_width + 20); 315 r.size.x = max_text_width + 20; 316 317 v4 fg = normalize_colour((Colour){.rgba = 0x1e9e33ff}); 318 v4 bg = normalize_colour((Colour){.rgba = 0x090909bf}); 319 320 push_rect(rc, r, bg); 321 322 u32 font_id = g_ui_debug_font_id; 323 f32 line_pad = 5; 324 v2 txt_pos = {.x = r.pos.x, .y = ws.h - 20}; 325 326 Stream txt = stream_alloc(&memory, 1024); 327 { 328 stream_push_s8(&txt, s8("Render Time: ")); 329 stream_push_f64(&txt, dt_for_frame * 1e3, 100); 330 stream_push_s8(&txt, s8(" ms/f")); 331 v2 ts = measure_text(rc, font_id, stream_to_s8(&txt)); 332 txt_pos.y = (u32)(txt_pos.y - ts.h - line_pad); 333 push_s8(rc, txt_pos, fg, font_id, stream_to_s8(&txt)); 334 335 if (ts.w > max_text_width) max_text_width = ts.w; 336 if (ts.h > line_height) line_height = ts.h; 337 } 338 339 GlyphCacheStats new_glyph_stats = get_and_clear_glyph_cache_stats(&t->fa.glyph_cache); 340 if (new_glyph_stats.hit_count != 0) 341 glyph_stats = new_glyph_stats; 342 { 343 s8 header = s8("Glyph Cache Stats:"); 344 txt_pos.y = (u32)(txt_pos.y - line_height - line_pad); 345 v2 ts = push_s8(rc, txt_pos, fg, font_id, header); 346 347 /* TODO: This doesn't really work when we are redrawing on every frame */ 348 static s8 fmts[ARRAY_COUNT(glyph_stats.E)] = { 349 s8(" Hits: "), 350 s8(" Misses: "), 351 s8(" Recycles: "), 352 }; 353 for (u32 i = 0; i < ARRAY_COUNT(glyph_stats.E); i++) { 354 txt.widx = 0; 355 stream_push_s8(&txt, fmts[i]); 356 stream_push_u64(&txt, glyph_stats.E[i]); 357 txt_pos.y = (u32)(txt_pos.y - line_height - line_pad); 358 ts = push_s8(rc, txt_pos, fg, font_id, stream_to_s8(&txt)); 359 360 if (ts.w > max_text_width) max_text_width = ts.w; 361 if (ts.h > line_height) line_height = ts.h; 362 } 363 } 364 365 r.pos.y = txt_pos.y - 2 * line_pad; 366 r.size.h = ws.h - r.pos.y; 367 368 flush_render_push_buffer(rc); 369 370 END_TIMED_BLOCK(); 371 } 372 373 static void 374 debug_init(TerminalMemory *memory) 375 { 376 DebugState *ds = memory->debug_memory; 377 Arena a = {.beg = (u8 *)(ds + 1), .end = memory->debug_memory + memory->debug_memory_size}; 378 ds->memory = a; 379 ds->temp_memory = begin_temp_arena(&ds->memory); 380 ds->initialized = 1; 381 ds->bar_thickness = 14; 382 ds->frame_target_time = 4e-3; 383 restart_collation(ds, g_debug_table.snapshot_index); 384 } 385 386 static void 387 debug_frame_end(TerminalMemory *memory, TerminalInput *input) 388 { 389 DebugState *debug_state = memory->debug_memory; 390 if (!debug_state->initialized) 391 debug_init(memory); 392 393 g_debug_table.snapshot_index++; 394 if (g_debug_table.snapshot_index == MAX_DEBUG_RECORD_COUNT) 395 g_debug_table.snapshot_index = 0; 396 u64 event_array_event_index = atomic_exchange_n(&g_debug_table.event_array_event_index, 397 (u64)g_debug_table.snapshot_index << 32); 398 399 FRAME_MARK(input->dt); 400 401 u32 array_index = event_array_event_index >> 32; 402 u32 event_count = event_array_event_index & 0xFFFFFFFF; 403 404 g_debug_table.events_count[array_index] = event_count; 405 g_debug_table.metadata_count = __COUNTER__; 406 407 if (!debug_state->paused) { 408 if (debug_state->record_count >= 2*MAX_DEBUG_RECORD_COUNT) 409 restart_collation(debug_state, g_debug_table.snapshot_index); 410 coalesce_debug_events(debug_state, g_debug_table.snapshot_index); 411 } 412 }