Merge pull request #49647 from topolarity/timing-refactor

Make `jl_timer_block_t` allocation separate from timer-start (JL_TIMING)

Author: topolarity

src/ast.c

@@ -784,7 +784,7 @@ JL_DLLEXPORT jl_value_t *jl_fl_parse(const char *text, size_t text_len,
                                      size_t offset, jl_value_t *options)
 {
     JL_TIMING(PARSING, PARSING);
-    jl_timing_show_filename(jl_string_data(filename), JL_TIMING_CURRENT_BLOCK);
+    jl_timing_show_filename(jl_string_data(filename), JL_TIMING_DEFAULT_BLOCK);
     if (offset > text_len) {
         jl_value_t *textstr = jl_pchar_to_string(text, text_len);
         JL_GC_PUSH1(&textstr);

src/codegen.cpp

@@ -8517,7 +8517,7 @@ jl_llvm_functions_t jl_emit_code(
         jl_codegen_params_t &params)
 {
     JL_TIMING(CODEGEN, CODEGEN_LLVM);
-    jl_timing_show_func_sig((jl_value_t *)li->specTypes, JL_TIMING_CURRENT_BLOCK);
+    jl_timing_show_func_sig((jl_value_t *)li->specTypes, JL_TIMING_DEFAULT_BLOCK);
     // caller must hold codegen_lock
     jl_llvm_functions_t decls = {};
     assert((params.params == &jl_default_cgparams /* fast path */ || !params.cache ||
@@ -8579,7 +8579,7 @@ jl_llvm_functions_t jl_emit_codeinst(
         jl_codegen_params_t &params)
 {
     JL_TIMING(CODEGEN, CODEGEN_Codeinst);
-    jl_timing_show_method_instance(codeinst->def, JL_TIMING_CURRENT_BLOCK);
+    jl_timing_show_method_instance(codeinst->def, JL_TIMING_DEFAULT_BLOCK);
     JL_GC_PUSH1(&src);
     if (!src) {
         src = (jl_code_info_t*)jl_atomic_load_relaxed(&codeinst->inferred);

src/dlload.c

@@ -284,7 +284,7 @@ JL_DLLEXPORT void *jl_load_dynamic_library(const char *modname, unsigned flags,
 
     JL_TIMING(DL_OPEN, DL_OPEN);
     if (!(flags & JL_RTLD_NOLOAD))
-        jl_timing_puts(JL_TIMING_CURRENT_BLOCK, modname);
+        jl_timing_puts(JL_TIMING_DEFAULT_BLOCK, modname);
 
     // Detect if our `modname` is something like `@rpath/libfoo.dylib`
 #ifdef _OS_DARWIN_
@@ -342,7 +342,7 @@ JL_DLLEXPORT void *jl_load_dynamic_library(const char *modname, unsigned flags,
 #endif
                         handle = jl_dlopen(path, flags);
                         if (handle && !(flags & JL_RTLD_NOLOAD))
-                            jl_timing_puts(JL_TIMING_CURRENT_BLOCK, jl_pathname_for_handle(handle));
+                            jl_timing_puts(JL_TIMING_DEFAULT_BLOCK, jl_pathname_for_handle(handle));
                         if (handle)
                             return handle;
 #ifdef _OS_WINDOWS_
@@ -364,7 +364,7 @@ JL_DLLEXPORT void *jl_load_dynamic_library(const char *modname, unsigned flags,
         snprintf(path, PATHBUF, "%s%s", modname, ext);
         handle = jl_dlopen(path, flags);
         if (handle && !(flags & JL_RTLD_NOLOAD))
-            jl_timing_puts(JL_TIMING_CURRENT_BLOCK, jl_pathname_for_handle(handle));
+            jl_timing_puts(JL_TIMING_DEFAULT_BLOCK, jl_pathname_for_handle(handle));
         if (handle)
             return handle;
 #ifdef _OS_WINDOWS_

src/gc.c

@@ -205,7 +205,7 @@ void jl_gc_wait_for_the_world(jl_ptls_t* gc_all_tls_states, int gc_n_threads)
 {
     JL_TIMING(GC, GC_Stop);
 #ifdef USE_TRACY
-    TracyCZoneCtx ctx = *(JL_TIMING_CURRENT_BLOCK->tracy_ctx);
+    TracyCZoneCtx ctx = JL_TIMING_DEFAULT_BLOCK->tracy_ctx;
     TracyCZoneColor(ctx, 0x696969);
 #endif
     assert(gc_n_threads);
@@ -3307,12 +3307,13 @@ static int _jl_gc_collect(jl_ptls_t ptls, jl_gc_collection_t collection)
     uint64_t start_sweep_time = jl_hrtime();
     JL_PROBE_GC_SWEEP_BEGIN(sweep_full);
     {
-        JL_TIMING(GC, GC_Sweep);
+        JL_TIMING_CREATE_BLOCK(incremental_timing_block,
+                               GC, GC_IncrementalSweep);
+        JL_TIMING_CREATE_BLOCK(full_timing_block,
+                               GC, GC_FullSweep);
+        jl_timing_block_start(sweep_full ? &full_timing_block : &incremental_timing_block);
 #ifdef USE_TRACY
-        if (sweep_full) {
-            TracyCZoneCtx ctx = *(JL_TIMING_CURRENT_BLOCK->tracy_ctx);
-            TracyCZoneColor(ctx, 0xFFA500);
-        }
+        TracyCZoneColor(full_timing_block.tracy_ctx, 0xFFA500);
 #endif
         sweep_weak_refs();
         sweep_stack_pools();
@@ -3456,7 +3457,7 @@ JL_DLLEXPORT void jl_gc_collect(jl_gc_collection_t collection)
         return;
     }
 
-    JL_TIMING_SUSPEND(GC, ct);
+    JL_TIMING_SUSPEND_TASK(GC, ct);
     JL_TIMING(GC, GC);
 
     int last_errno = errno;

src/gf.c

@@ -367,7 +367,7 @@ jl_code_info_t *jl_type_infer(jl_method_instance_t *mi, size_t world, int force)
     fargs[1] = (jl_value_t*)mi;
     fargs[2] = jl_box_ulong(world);
 
-    jl_timing_show_method_instance(mi, JL_TIMING_CURRENT_BLOCK);
+    jl_timing_show_method_instance(mi, JL_TIMING_DEFAULT_BLOCK);
 #ifdef TRACE_INFERENCE
     if (mi->specTypes != (jl_value_t*)jl_emptytuple_type) {
         jl_printf(JL_STDERR,"inference on ");
@@ -1986,7 +1986,7 @@ JL_DLLEXPORT void jl_method_table_insert(jl_methtable_t *mt, jl_method_t *method
     JL_TIMING(ADD_METHOD, ADD_METHOD);
     assert(jl_is_method(method));
     assert(jl_is_mtable(mt));
-    jl_timing_show_method(method, JL_TIMING_CURRENT_BLOCK);
+    jl_timing_show_method(method, JL_TIMING_DEFAULT_BLOCK);
     jl_value_t *type = method->sig;
     jl_value_t *oldvalue = NULL;
     jl_array_t *oldmi = NULL;

src/jitlayers.cpp

@@ -190,8 +190,7 @@ static jl_callptr_t _jl_compile_codeinst(
     JL_TIMING(CODEINST_COMPILE, CODEINST_COMPILE);
 #ifdef USE_TRACY
     if (is_recompile) {
-        TracyCZoneCtx ctx = *(JL_TIMING_CURRENT_BLOCK->tracy_ctx);
-        TracyCZoneColor(ctx, 0xFFA500);
+        TracyCZoneColor(JL_TIMING_DEFAULT_BLOCK->tracy_ctx, 0xFFA500);
     }
 #endif
     jl_callptr_t fptr = NULL;
@@ -252,7 +251,7 @@ static jl_callptr_t _jl_compile_codeinst(
     for (auto &def : emitted) {
         jl_code_instance_t *this_code = def.first;
         if (i < jl_timing_print_limit)
-            jl_timing_show_func_sig(this_code->def->specTypes, JL_TIMING_CURRENT_BLOCK);
+            jl_timing_show_func_sig(this_code->def->specTypes, JL_TIMING_DEFAULT_BLOCK);
 
         jl_llvm_functions_t decls = std::get<1>(def.second);
         jl_callptr_t addr;
@@ -301,7 +300,7 @@ static jl_callptr_t _jl_compile_codeinst(
         i++;
     }
     if (i > jl_timing_print_limit)
-        jl_timing_printf(JL_TIMING_CURRENT_BLOCK, "... <%d methods truncated>", i - 10);
+        jl_timing_printf(JL_TIMING_DEFAULT_BLOCK, "... <%d methods truncated>", i - 10);
 
     uint64_t end_time = 0;
     if (timed)

src/method.c

@@ -569,7 +569,7 @@ JL_DLLEXPORT jl_code_info_t *jl_code_for_staged(jl_method_instance_t *linfo, siz
     JL_TIMING(STAGED_FUNCTION, STAGED_FUNCTION);
     jl_value_t *tt = linfo->specTypes;
     jl_method_t *def = linfo->def.method;
-    jl_timing_show_method_instance(linfo, JL_TIMING_CURRENT_BLOCK);
+    jl_timing_show_method_instance(linfo, JL_TIMING_DEFAULT_BLOCK);
     jl_value_t *generator = def->generator;
     assert(generator != NULL);
     assert(jl_is_method(def));

src/safepoint.c

@@ -151,7 +151,7 @@ void jl_safepoint_end_gc(void)
 void jl_safepoint_wait_gc(void)
 {
     jl_task_t *ct = jl_current_task; (void)ct;
-    JL_TIMING_SUSPEND(GC_SAFEPOINT, ct);
+    JL_TIMING_SUSPEND_TASK(GC_SAFEPOINT, ct);
     // The thread should have set this is already
     assert(jl_atomic_load_relaxed(&ct->ptls->gc_state) != 0);
     // Use normal volatile load in the loop for speed until GC finishes.

src/staticdata.c

@@ -3367,7 +3367,7 @@ static jl_value_t *jl_validate_cache_file(ios_t *f, jl_array_t *depmods, uint64_
 static jl_value_t *jl_restore_package_image_from_stream(ios_t *f, jl_image_t *image, jl_array_t *depmods, int completeinfo, const char *pkgname)
 {
     JL_TIMING(LOAD_IMAGE, LOAD_Pkgimg);
-    jl_timing_printf(JL_TIMING_CURRENT_BLOCK, pkgname);
+    jl_timing_printf(JL_TIMING_DEFAULT_BLOCK, pkgname);
     uint64_t checksum = 0;
     int64_t dataendpos = 0;
     int64_t datastartpos = 0;

src/timing.c

@@ -44,16 +44,12 @@ JL_DLLEXPORT uint32_t jl_timing_print_limit = 10;
 const char *jl_timing_names[(int)JL_TIMING_LAST] =
     {
 #define X(name) #name,
-        JL_TIMING_OWNERS
+        JL_TIMING_SUBSYSTEMS
 #undef X
     };
 
 JL_DLLEXPORT jl_timing_counter_t jl_timing_counters[JL_TIMING_COUNTER_LAST];
 
-#ifdef USE_ITTAPI
-JL_DLLEXPORT __itt_event jl_timing_ittapi_events[(int)JL_TIMING_EVENT_LAST];
-#endif
-
 void jl_print_timings(void)
 {
 #ifdef USE_TIMING_COUNTS
@@ -91,9 +87,6 @@ void jl_init_timing(void)
 
     int i __attribute__((unused)) = 0;
 #ifdef USE_ITTAPI
-#define X(name) jl_timing_ittapi_events[i++] = __itt_event_create(#name, strlen(#name));
-    JL_TIMING_EVENTS
-#undef X
     i = 0;
 #define X(name) jl_timing_counters[i++].ittapi_counter = __itt_counter_create(#name, "julia.runtime");
     JL_TIMING_COUNTERS
@@ -187,7 +180,7 @@ JL_DLLEXPORT void jl_timing_show(jl_value_t *v, jl_timing_block_t *cur_block)
     if (buf.size == buf.maxsize)
         memset(&buf.buf[IOS_INLSIZE - 3], '.', 3);
 
-    TracyCZoneText(*(cur_block->tracy_ctx), buf.buf, buf.size);
+    TracyCZoneText(cur_block->tracy_ctx, buf.buf, buf.size);
 #endif
 }
 
@@ -197,7 +190,7 @@ JL_DLLEXPORT void jl_timing_show_module(jl_module_t *m, jl_timing_block_t *cur_b
     jl_module_t *root = jl_module_root(m);
     if (root == m || root == jl_main_module) {
         const char *module_name = jl_symbol_name(m->name);
-        TracyCZoneText(*(cur_block->tracy_ctx), module_name, strlen(module_name));
+        TracyCZoneText(cur_block->tracy_ctx, module_name, strlen(module_name));
     } else {
         jl_timing_printf(cur_block, "%s.%s", jl_symbol_name(root->name), jl_symbol_name(m->name));
     }
@@ -208,7 +201,7 @@ JL_DLLEXPORT void jl_timing_show_filename(const char *path, jl_timing_block_t *c
 {
 #ifdef USE_TRACY
     const char *filename = gnu_basename(path);
-    TracyCZoneText(*(cur_block->tracy_ctx), filename, strlen(filename));
+    TracyCZoneText(cur_block->tracy_ctx, filename, strlen(filename));
 #endif
 }
 
@@ -243,7 +236,7 @@ JL_DLLEXPORT void jl_timing_show_func_sig(jl_value_t *v, jl_timing_block_t *cur_
     if (buf.size == buf.maxsize)
         memset(&buf.buf[IOS_INLSIZE - 3], '.', 3);
 
-    TracyCZoneText(*(cur_block->tracy_ctx), buf.buf, buf.size);
+    TracyCZoneText(cur_block->tracy_ctx, buf.buf, buf.size);
 #endif
 }
 
@@ -261,15 +254,15 @@ JL_DLLEXPORT void jl_timing_printf(jl_timing_block_t *cur_block, const char *for
     if (buf.size == buf.maxsize)
         memset(&buf.buf[IOS_INLSIZE - 3], '.', 3);
 
-    TracyCZoneText(*(cur_block->tracy_ctx), buf.buf, buf.size);
+    TracyCZoneText(cur_block->tracy_ctx, buf.buf, buf.size);
 #endif
     va_end(args);
 }
 
 JL_DLLEXPORT void jl_timing_puts(jl_timing_block_t *cur_block, const char *str)
 {
 #ifdef USE_TRACY
-    TracyCZoneText(*(cur_block->tracy_ctx), str, strlen(str));
+    TracyCZoneText(cur_block->tracy_ctx, str, strlen(str));
 #endif
 }