GC: enable logging to stderr when GC runs

base/experimental.jl

@@ -344,4 +344,13 @@ adding them to the global method table.
 """
 :@MethodTable
 
+"""
+    Experimental.enable_gc_logging(on::Bool)
+
+When turned on, print statistics about each GC to stdout.
+"""
+function enable_gc_logging(on::Bool=true)
+    ccall(:jl_enable_gc_logging, Cvoid, (Cint,), on)
+end
+
 end

src/gc-debug.c

@@ -1380,6 +1380,23 @@ NOINLINE void gc_mark_loop_unwind(jl_ptls_t ptls, jl_gc_mark_sp_t sp, int pc_off
     jl_set_safe_restore(old_buf);
 }
 
+static int gc_logging_enabled = 0;
+
+JL_DLLEXPORT void jl_enable_gc_logging(int enable) {
+    gc_logging_enabled = enable;
+}
+
+void _report_gc_finished(uint64_t pause, uint64_t freed, int full, int recollect) JL_NOTSAFEPOINT {
+    if (!gc_logging_enabled) {
+        return;
+    }
+    jl_safe_printf("GC: pause %.2fms. collected %fMB. %s %s\n",
+        pause/1e6, freed/1e6,
+        full ? "full" : "incr",
+        recollect ? "recollect" : ""
+    );
+}
+
 #ifdef __cplusplus
 }
 #endif

src/gc.c

@@ -3205,6 +3205,9 @@ static int _jl_gc_collect(jl_ptls_t ptls, jl_gc_collection_t collection)
 
     uint64_t gc_end_t = jl_hrtime();
     uint64_t pause = gc_end_t - t0;
+
+    _report_gc_finished(pause, gc_num.freed, sweep_full, recollect);
+
     gc_final_pause_end(t0, gc_end_t);
     gc_time_sweep_pause(gc_end_t, actual_allocd, live_bytes,
                         estimate_freed, sweep_full);

src/gc.h

@@ -696,6 +696,9 @@ void gc_count_pool(void);
 
 size_t jl_array_nbytes(jl_array_t *a) JL_NOTSAFEPOINT;
 
+JL_DLLEXPORT void jl_enable_gc_logging(int enable);
+void _report_gc_finished(uint64_t pause, uint64_t freed, int full, int recollect) JL_NOTSAFEPOINT;
+
 #ifdef __cplusplus
 }
 #endif