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