From ec13092a351b5055498d364d6a01b77b0cfc9ac4 Mon Sep 17 00:00:00 2001 From: Ryan Fleury Date: Tue, 23 Apr 2024 09:57:17 -0700 Subject: [PATCH] ui thread logging; more ctrl thread logging --- src/ctrl/ctrl_core.c | 16 ++++++++++++---- src/ctrl/ctrl_core.h | 6 ++++++ src/df/core/df_core.c | 40 ++++++++++++++++++++++++++++++++++++++++ src/os/core/os_core.c | 15 +++++++++------ src/raddbg/raddbg.c | 19 +++++++++++++++++++ src/raddbg/raddbg.h | 2 ++ 6 files changed, 88 insertions(+), 10 deletions(-) diff --git a/src/ctrl/ctrl_core.c b/src/ctrl/ctrl_core.c index 47c3ab35..464956ff 100644 --- a/src/ctrl/ctrl_core.c +++ b/src/ctrl/ctrl_core.c @@ -2107,7 +2107,9 @@ ctrl_thread__next_dmn_event(Arena *arena, DMN_CtrlCtx *ctrl_ctx, CTRL_Msg *msg, // rjf: run for new events ProfScope("run for new events") { + CTRL_CtrlThreadLogScope log_msgf("{dmn_ctrl_run ..."); DMN_EventList events = dmn_ctrl_run(scratch.arena, ctrl_ctx, run_ctrls); + CTRL_CtrlThreadLogScope log_msgf("}\n"); for(DMN_EventNode *src_n = events.first; src_n != 0; src_n = src_n->next) { DMN_EventNode *dst_n = ctrl_state->free_dmn_event_node; @@ -2299,10 +2301,16 @@ ctrl_eval_memory_read(void *u, void *out, U64 addr, U64 size) internal void ctrl_thread__flush_log(String8 string) { - if(string.size != 0) - { - os_append_data_to_file_path(ctrl_state->ctrl_thread_log_path, string); - } + os_append_data_to_file_path(ctrl_state->ctrl_thread_log_path, string); +} + +internal void +ctrl_thread__end_and_flush_log(void) +{ + Temp scratch = scratch_begin(0, 0); + String8 log = log_scope_end(scratch.arena); + ctrl_thread__flush_log(log); + scratch_end(scratch); } //- rjf: msg kind implementations diff --git a/src/ctrl/ctrl_core.h b/src/ctrl/ctrl_core.h index 3f671f5a..2c078221 100644 --- a/src/ctrl/ctrl_core.h +++ b/src/ctrl/ctrl_core.h @@ -553,6 +553,11 @@ read_only global CTRL_Entity ctrl_entity_nil = &ctrl_entity_nil, }; +//////////////////////////////// +//~ rjf: Logging Markup + +#define CTRL_CtrlThreadLogScope DeferLoop(log_scope_begin(), ctrl_thread__end_and_flush_log()) + //////////////////////////////// //~ rjf: Basic Type Functions @@ -712,6 +717,7 @@ internal B32 ctrl_eval_memory_read(void *u, void *out, U64 addr, U64 size); //- rjf: log flusher internal void ctrl_thread__flush_log(String8 string); +internal void ctrl_thread__end_and_flush_log(void); //- rjf: msg kind implementations internal void ctrl_thread__launch(DMN_CtrlCtx *ctrl_ctx, CTRL_Msg *msg); diff --git a/src/df/core/df_core.c b/src/df/core/df_core.c index 74740ff8..80c6629f 100644 --- a/src/df/core/df_core.c +++ b/src/df/core/df_core.c @@ -1798,6 +1798,9 @@ df_entity_alloc(DF_StateDeltaHistory *hist, DF_Entity *parent, DF_EntityKind kin df_state->kind_alloc_gens[kind] += 1; df_entity_notify_mutation(entity); + // rjf: log + log_msgf("new entity: %S $%I64d\n", df_g_entity_kind_display_string_table[kind], entity->id); + return entity; } @@ -1841,6 +1844,7 @@ df_entity_release(DF_StateDeltaHistory *hist, DF_Entity *entity) t->e = child; SLLQueuePush(first_task, last_task, t); } + log_msgf("end entity: %S $%I64d\n", task->e->kind, task->e->id); df_state_delta_history_push_struct_delta(hist, &task->e->first); df_state_delta_history_push_struct_delta(hist, &task->e->last); df_state_delta_history_push_struct_delta(hist, &task->e->next); @@ -6449,6 +6453,42 @@ df_query_cached_member_map_from_binary_voff(DF_Entity *binary, U64 voff) internal void df_push_cmd__root(DF_CmdParams *params, DF_CmdSpec *spec) { + // rjf: log + { + Temp scratch = scratch_begin(0, 0); + DF_Entity *entity = df_entity_from_handle(params->entity); + log_msgf("debug frontend command pushed: \"%S\"\n", spec->info.string); +#define HandleParamPrint(mem_name) if(!df_handle_match(df_handle_zero(), params->mem_name)) { log_msgf(" %s: [0x%I64x, 0x%I64x]\n", #mem_name, params->mem_name.u64[0], params->mem_name.u64[1]); } + HandleParamPrint(window); + HandleParamPrint(panel); + HandleParamPrint(dest_panel); + HandleParamPrint(prev_view); + HandleParamPrint(view); + if(!df_entity_is_nil(entity)) + { + String8 entity_name = df_display_string_from_entity(scratch.arena, entity); + log_msgf(" entity: \"%S\"\n", entity_name); + } + U64 idx = 0; + for(DF_HandleNode *n = params->entity_list.first; n != 0; n = n->next, idx += 1) + { + DF_Entity *entity = df_entity_from_handle(n->handle); + if(!df_entity_is_nil(entity)) + { + String8 entity_name = df_display_string_from_entity(scratch.arena, entity); + log_msgf(" entity_list[%I64u]: \"%S\"\n", idx, entity_name); + } + } + if(params->string.size != 0) { log_msgf(" string: \"%S\"\n", params->string); } + if(params->file_path.size != 0) { log_msgf(" file_path: \"%S\"\n", params->file_path); } + if(params->text_point.line != 0){ log_msgf(" text_point: [line:%I64d, col:%I64d]\n", params->text_point.line, params->text_point.column); } + if(params->vaddr != 0) { log_msgf(" vaddr: 0x%I64x\n", params->vaddr); } + if(params->voff != 0) { log_msgf(" voff: 0x%I64x\n", params->voff); } + if(params->index != 0) { log_msgf(" index: 0x%I64x\n", params->index); } + if(params->id != 0) { log_msgf(" id: 0x%I64x\n", params->id); } +#undef HandleParamPrint + scratch_end(scratch); + } df_cmd_list_push(df_state->root_cmd_arena, &df_state->root_cmds, params, spec); } diff --git a/src/os/core/os_core.c b/src/os/core/os_core.c index 830fc677..cf96fe1f 100644 --- a/src/os/core/os_core.c +++ b/src/os/core/os_core.c @@ -117,13 +117,16 @@ internal B32 os_append_data_to_file_path(String8 path, String8 data) { B32 good = 0; - OS_Handle file = os_file_open(OS_AccessFlag_Write|OS_AccessFlag_Append, path); - if(!os_handle_match(file, os_handle_zero())) + if(data.size != 0) { - good = 1; - U64 pos = os_properties_from_file(file).size; - os_file_write(file, r1u64(pos, pos+data.size), data.str); - os_file_close(file); + OS_Handle file = os_file_open(OS_AccessFlag_Write|OS_AccessFlag_Append, path); + if(!os_handle_match(file, os_handle_zero())) + { + good = 1; + U64 pos = os_properties_from_file(file).size; + os_file_write(file, r1u64(pos, pos+data.size), data.str); + os_file_close(file); + } } return good; } diff --git a/src/raddbg/raddbg.c b/src/raddbg/raddbg.c index 12a3e395..9d58a847 100644 --- a/src/raddbg/raddbg.c +++ b/src/raddbg/raddbg.c @@ -11,6 +11,19 @@ update_and_render(OS_Handle repaint_window_handle, void *user_data) ProfBeginFunction(); Temp scratch = scratch_begin(0, 0); + //- rjf: begin logging + if(main_thread_log == 0) + { + main_thread_log = log_alloc(); + String8 user_program_data_path = os_string_from_system_path(scratch.arena, OS_SystemPath_UserProgramData); + String8 user_data_folder = push_str8f(scratch.arena, "%S/raddbg/logs", user_program_data_path); + main_thread_log_path = push_str8f(df_state->arena, "%S/ui_thread.raddbg_log", user_data_folder); + os_make_directory(user_data_folder); + os_write_data_to_file_path(main_thread_log_path, str8_zero()); + } + log_select(main_thread_log); + log_scope_begin(); + //- rjf: tick cache layers txt_user_clock_tick(); geo_user_clock_tick(); @@ -328,6 +341,12 @@ update_and_render(OS_Handle repaint_window_handle, void *user_data) frame_time_us_history[frame_time_us_history_idx%ArrayCount(frame_time_us_history)] = frame_time_us; frame_time_us_history_idx += 1; + //- rjf: end logging + { + String8 log = log_scope_end(scratch.arena); + os_append_data_to_file_path(main_thread_log_path, log); + } + scratch_end(scratch); ProfEnd(); } diff --git a/src/raddbg/raddbg.h b/src/raddbg/raddbg.h index 513f9990..28cc5519 100644 --- a/src/raddbg/raddbg.h +++ b/src/raddbg/raddbg.h @@ -442,6 +442,8 @@ read_only global String8 ipc_shared_memory_name = str8_lit_comp("_raddbg_ipc_sha read_only global String8 ipc_semaphore_name = str8_lit_comp("_raddbg_ipc_semaphore_"); global U64 frame_time_us_history[64] = {0}; global U64 frame_time_us_history_idx = 0; +global Log *main_thread_log = 0; +global String8 main_thread_log_path = {0}; //////////////////////////////// //~ rjf: Frontend Entry Points