* gc.c: added GC::Profiler.

git-svn-id: svn+ssh://ci.ruby-lang.org/ruby/trunk@18493 b2dd03c8-39d4-4d8f-98ff-823fe69b080e

1 files changed, 339 insertions, 0 deletions

diff --git a/gc.c b/gc.c
index e408570ad3..118c49ebd6 100644
--- a/gc.c
+++ b/gc.c
@@ -92,6 +92,132 @@ int ruby_gc_debug_indent = 0;
 
 #undef GC_DEBUG
 
+/* for GC profile */
+#define GC_PROFILE_MORE_DETAIL 0
+typedef struct gc_profile_record {
+    double gc_time;
+    double gc_mark_time;
+    double gc_sweep_time;
+    double gc_invoke_time;
+    size_t heap_use_slots;
+    size_t heap_live_objects;
+    size_t heap_free_objects;
+    size_t heap_total_objects;
+    size_t heap_use_size;
+    size_t heap_total_size;
+    int have_finalize;
+    size_t allocate_increase;
+    size_t allocate_limit;
+} gc_profile_record;
+
+static double
+getrusage_time(void)
+{
+    struct rusage usage;
+    struct timeval time;
+    getrusage(RUSAGE_SELF, &usage);
+    time = usage.ru_utime;
+    return time.tv_sec + time.tv_usec * 1e-6;
+}
+
+#define GC_PROF_TIMER_START do {\
+	if (objspace->profile.run) {\
+	    if (!objspace->profile.record) {\
+		objspace->profile.size = 1000;\
+		objspace->profile.record = malloc(sizeof(gc_profile_record) * objspace->profile.size);\
+	    }\
+	    if (count >= objspace->profile.size) {\
+		objspace->profile.size += 1000;\
+		objspace->profile.record = realloc(objspace->profile.record, sizeof(gc_profile_record) * objspace->profile.size);\
+	    }\
+	    if (!objspace->profile.record) {\
+		rb_bug("gc_profile malloc or realloc miss");\
+	    }\
+	    MEMZERO(&objspace->profile.record[count], gc_profile_record, 1);\
+	    gc_time = getrusage_time();\
+	    objspace->profile.record[count].gc_invoke_time = gc_time - objspace->profile.invoke_time;\
+	}\
+    } while(0)
+
+#define GC_PROF_TIMER_STOP do {\
+	if (objspace->profile.run) {\
+	    gc_time = getrusage_time() - gc_time;\
+	    if(gc_time < 0) gc_time = 0;\
+	    objspace->profile.record[count].gc_time = gc_time;\
+	    objspace->profile.count++;\
+	}\
+    } while(0)
+
+#if GC_PROFILE_MORE_DETAIL
+#define INIT_GC_PROF_PARAMS double gc_time = 0, mark_time = 0, sweep_time = 0;\
+    size_t count = objspace->profile.count
+
+#define GC_PROF_MARK_TIMER_START do {\
+	if (objspace->profile.run) {\
+	    mark_time = getrusage_time();\
+	}\
+    } while(0)
+
+#define GC_PROF_MARK_TIMER_STOP do {\
+	if (objspace->profile.run) {\
+	    mark_time = getrusage_time() - mark_time;\
+	    if (mark_time < 0) mark_time = 0;\
+	    objspace->profile.record[count].gc_mark_time = mark_time;\
+	}\
+    } while(0)
+
+#define GC_PROF_SWEEP_TIMER_START do {\
+	if (objspace->profile.run) {\
+	    sweep_time = getrusage_time();\
+	}\
+    } while(0)
+
+#define GC_PROF_SWEEP_TIMER_STOP do {\
+	if (objspace->profile.run) {\
+	    sweep_time = getrusage_time() - sweep_time;\
+	    if (sweep_time < 0) sweep_time = 0;\
+	    objspace->profile.record[count].gc_sweep_time = sweep_time;\
+	}\
+    } while(0)
+#define GC_PROF_SET_MALLOC_INFO do {\
+	if (objspace->profile.run) {\
+	    size_t count = objspace->profile.count;\
+	    objspace->profile.record[count].allocate_increase = malloc_increase;\
+	    objspace->profile.record[count].allocate_limit = malloc_limit; \
+	}\
+    } while(0)
+#define GC_PROF_SET_HEAP_INFO do {\
+	if (objspace->profile.run) {\
+	    size_t count = objspace->profile.count;\
+	    objspace->profile.record[count].heap_use_slots = heaps_used;\
+	    objspace->profile.record[count].heap_live_objects = live;\
+	    objspace->profile.record[count].heap_free_objects = freed;\
+	    objspace->profile.record[count].heap_total_objects = heaps_used * HEAP_OBJ_LIMIT;\
+	    objspace->profile.record[count].have_finalize = final_list ? Qtrue : Qfalse;\
+	    objspace->profile.record[count].heap_use_size = live * sizeof(RVALUE);\
+	    objspace->profile.record[count].heap_total_size = heaps_used * (HEAP_OBJ_LIMIT * sizeof(RVALUE));\
+	}\
+    } while(0)
+
+#else
+#define INIT_GC_PROF_PARAMS double gc_time = 0;\
+    size_t count = objspace->profile.count
+#define GC_PROF_MARK_TIMER_START
+#define GC_PROF_MARK_TIMER_STOP
+#define GC_PROF_SWEEP_TIMER_START
+#define GC_PROF_SWEEP_TIMER_STOP
+#define GC_PROF_SET_MALLOC_INFO
+#define GC_PROF_SET_HEAP_INFO do {\
+	if (objspace->profile.run) {\
+	    size_t count = objspace->profile.count;\
+	    objspace->profile.record[count].heap_total_objects = heaps_used * HEAP_OBJ_LIMIT;\
+	    objspace->profile.record[count].heap_use_size = live * sizeof(RVALUE);\
+	    objspace->profile.record[count].heap_total_size = heaps_used * HEAP_SIZE;\
+	}\
+    } while(0)
+#endif
+
+
 #if defined(_MSC_VER) || defined(__BORLANDC__) || defined(__CYGWIN__)
 #pragma pack(push, 1) /* magic for reducing sizeof(RVALUE): 24 -> 20 */
 #endif
@@ -176,6 +302,13 @@ typedef struct rb_objspace {
 	VALUE *ptr;
 	int overflow;
     } markstack;
+    struct {
+	int run;
+	gc_profile_record *record;
+	size_t count;
+	size_t size;
+	double invoke_time;
+    } profile;
     struct gc_list *global_list;
     unsigned int count;
     int gc_stress;
@@ -309,6 +442,73 @@ gc_stress_set(VALUE self, VALUE bool)
     return bool;
 }
 
+/*
+ *  call-seq:
+ *    GC::Profiler.enable?                 => true or false
+ *
+ *  returns current status of GC profile mode.
+ */
+
+static VALUE
+gc_profile_enable_get(VALUE self)
+{
+    rb_objspace_t *objspace = &rb_objspace;
+    return objspace->profile.run;
+}
+
+/*
+ *  call-seq:
+ *    GC::Profiler.enable          => nil
+ *
+ *  updates GC profile mode.
+ *  start profiler for GC.
+ *
+ */
+
+static VALUE
+gc_profile_enable(void)
+{
+    rb_objspace_t *objspace = &rb_objspace;
+
+    objspace->profile.run = Qtrue;
+    return Qnil;
+}
+
+/*
+ *  call-seq:
+ *    GC::Profiler.disable          => nil
+ *
+ *  updates GC profile mode.
+ *  stop profiler for GC.
+ *
+ */
+
+static VALUE
+gc_profile_disable(void)
+{
+    rb_objspace_t *objspace = &rb_objspace;
+
+    objspace->profile.run = Qfalse;
+    return Qnil;
+}
+
+/*
+ *  call-seq:
+ *    GC::Profiler.clear          => nil
+ *
+ *  clear before profile data.
+ *
+ */
+
+static VALUE
+gc_profile_clear(void)
+{
+    rb_objspace_t *objspace = &rb_objspace;
+    MEMZERO(objspace->profile.record, gc_profile_record, objspace->profile.size);
+    objspace->profile.count = 0;
+    return Qnil;
+}
+
 static void *
 vm_xmalloc(rb_objspace_t *objspace, size_t size)
 {
@@ -634,6 +834,7 @@ init_heap(rb_objspace_t *objspace)
     	assign_heap_slot(objspace);
     }
     heaps_inc = 0;
+    objspace->profile.invoke_time = getrusage_time();
 }
 
 
@@ -1461,6 +1662,7 @@ gc_sweep(rb_objspace_t *objspace)
 	    freed += n;
 	}
     }
+    GC_PROF_SET_MALLOC_INFO;
     if (malloc_increase > malloc_limit) {
 	malloc_limit += (malloc_increase - malloc_limit) * (double)live / (live + freed);
 	if (malloc_limit < GC_MALLOC_LIMIT) malloc_limit = GC_MALLOC_LIMIT;
@@ -1474,11 +1676,13 @@ gc_sweep(rb_objspace_t *objspace)
 
     /* clear finalization list */
     if (final_list) {
+	GC_PROF_SET_HEAP_INFO;
 	deferred_final_list = final_list;
 	RUBY_VM_SET_FINALIZER_INTERRUPT(GET_THREAD());
     }
     else{
 	free_unused_heaps(objspace);
+	GC_PROF_SET_HEAP_INFO;
     }
 }
 
@@ -1706,6 +1910,7 @@ garbage_collect(rb_objspace_t *objspace)
 {
     struct gc_list *list;
     rb_thread_t *th = GET_THREAD();
+    INIT_GC_PROF_PARAMS;
 
     if (GC_NOTIFY) printf("start garbage_collect()\n");
 
@@ -1725,6 +1930,8 @@ garbage_collect(rb_objspace_t *objspace)
     during_gc++;
     objspace->count++;
 
+    GC_PROF_TIMER_START;
+    GC_PROF_MARK_TIMER_START;
     SET_STACK_END;
 
     init_mark_stack(objspace);
@@ -1765,9 +1972,13 @@ garbage_collect(rb_objspace_t *objspace)
 	    gc_mark_rest(objspace);
 	}
     }
+    GC_PROF_MARK_TIMER_STOP;
 
+    GC_PROF_SWEEP_TIMER_START;
     gc_sweep(objspace);
+    GC_PROF_SWEEP_TIMER_STOP;
 
+    GC_PROF_TIMER_STOP;
     if (GC_NOTIFY) printf("end garbage_collect()\n");
     return Qtrue;
 }
@@ -2354,6 +2565,7 @@ count_objects(int argc, VALUE *argv, VALUE os)
     }
     rb_hash_aset(hash, ID2SYM(rb_intern("TOTAL")), SIZET2NUM(total));
     rb_hash_aset(hash, ID2SYM(rb_intern("FREE")), SIZET2NUM(freed));
+
     for (i = 0; i <= T_MASK; i++) {
         VALUE type;
         switch (i) {
@@ -2441,6 +2653,124 @@ gc_malloc_allocations(VALUE self)
 }
 #endif
 
+VALUE
+gc_profile_record_get(void)
+{
+    VALUE prof;
+    VALUE gc_profile = rb_ary_new();
+    size_t i;
+    rb_objspace_t *objspace = (&rb_objspace);
+    
+    if (!objspace->profile.run) {
+	return Qnil;
+    }
+
+    for (i =0; i < objspace->profile.count; i++) {
+	prof = rb_hash_new();
+        rb_hash_aset(prof, ID2SYM(rb_intern("GC_TIME")), DOUBLE2NUM(objspace->profile.record[i].gc_time));
+        rb_hash_aset(prof, ID2SYM(rb_intern("GC_INVOKE_TIME")), DOUBLE2NUM(objspace->profile.record[i].gc_invoke_time));
+        rb_hash_aset(prof, ID2SYM(rb_intern("HEAP_USE_SIZE")), rb_uint2inum(objspace->profile.record[i].heap_use_size));
+        rb_hash_aset(prof, ID2SYM(rb_intern("HEAP_TOTAL_SIZE")), rb_uint2inum(objspace->profile.record[i].heap_total_size));
+        rb_hash_aset(prof, ID2SYM(rb_intern("HEAP_TOTAL_OBJECTS")), rb_uint2inum(objspace->profile.record[i].heap_total_objects));
+#if GC_PROFILE_MORE_DETAIL
+        rb_hash_aset(prof, ID2SYM(rb_intern("GC_MARK_TIME")), DOUBLE2NUM(objspace->profile.record[i].gc_mark_time));
+        rb_hash_aset(prof, ID2SYM(rb_intern("GC_SWEEP_TIME")), DOUBLE2NUM(objspace->profile.record[i].gc_sweep_time));
+        rb_hash_aset(prof, ID2SYM(rb_intern("ALLOCATE_INCREASE")), rb_uint2inum(objspace->profile.record[i].allocate_increase));
+        rb_hash_aset(prof, ID2SYM(rb_intern("ALLOCATE_LIMIT")), rb_uint2inum(objspace->profile.record[i].allocate_limit));
+        rb_hash_aset(prof, ID2SYM(rb_intern("HEAP_USE_SLOTS")), rb_uint2inum(objspace->profile.record[i].heap_use_slots));
+        rb_hash_aset(prof, ID2SYM(rb_intern("HEAP_LIVE_OBJECTS")), rb_uint2inum(objspace->profile.record[i].heap_live_objects));
+        rb_hash_aset(prof, ID2SYM(rb_intern("HEAP_FREE_OBJECTS")), rb_uint2inum(objspace->profile.record[i].heap_free_objects));
+        rb_hash_aset(prof, ID2SYM(rb_intern("HAVE_FINALIZE")), objspace->profile.record[i].have_finalize);
+#endif
+	rb_ary_push(gc_profile, prof);
+    }
+
+    return gc_profile;
+}
+
+/*
+ *  call-seq:
+ *     GC::Profiler.result -> string
+ *
+ *  Report profile data to string.
+ *  
+ *  It returns a string as:
+ *   GC 1 invokes.
+ *   Index    Invoke Time(sec)       Use Size(byte)     Total Size(byte)         Total Object                    GC time(ms)
+ *       1               0.012               159240               212940                10647         0.00000000000001530000
+ */
+
+VALUE
+gc_profile_result(void)
+{
+    rb_objspace_t *objspace = &rb_objspace;
+    VALUE record = gc_profile_record_get();
+    VALUE result = rb_str_new2("");
+    int i;
+    char buf[1024];
+    
+    if(objspace->profile.run && objspace->profile.count) {
+	sprintf(buf, "GC %1$d invokes.\n", NUM2INT(gc_count(0)));
+	rb_str_concat(result, rb_str_new2(buf));
+	rb_str_concat(result, rb_str_new2("Index    Invoke Time(sec)       Use Size(byte)     Total Size(byte)         Total Object                    GC Time(ms)\n"));
+	for(i = 0; i < (int)RARRAY_LEN(record); i++) {
+	    memset(buf, 0, 1024);
+	    VALUE r = RARRAY_PTR(record)[i];
+	    sprintf(buf, "%1$5d %2$19.3f %3$20d %4$20d %5$20d %6$30.20f\n",
+		    i+1, NUM2DBL(rb_hash_aref(r, ID2SYM(rb_intern("GC_INVOKE_TIME")))),
+		    NUM2INT(rb_hash_aref(r, ID2SYM(rb_intern("HEAP_USE_SIZE")))),
+		    NUM2INT(rb_hash_aref(r, ID2SYM(rb_intern("HEAP_TOTAL_SIZE")))),
+		    NUM2INT(rb_hash_aref(r, ID2SYM(rb_intern("HEAP_TOTAL_OBJECTS")))),
+		    NUM2DBL(rb_hash_aref(r, ID2SYM(rb_intern("GC_TIME"))))*100);
+	    rb_str_concat(result, rb_str_new2(buf));
+	}
+#if GC_PROFILE_MORE_DETAIL
+	rb_str_concat(result, rb_str_new2("\n\n"));
+	rb_str_concat(result, rb_str_new2("More detail.\n"));
+	rb_str_concat(result, rb_str_new2("Index Allocate Increase    Allocate Limit  Use Slot  Have Finalize             Mark Time(ms)            Sweep Time(ms)\n"));
+	for(i = 0; i < (int)RARRAY_LEN(record); i++) {
+	    memset(buf, 0, 1024);
+	    VALUE r = RARRAY_PTR(record)[i];
+	    sprintf(buf, "%1$5d %2$17d %3$17d %4$9d %5$14s %6$25.20f %7$25.20f\n",
+		    i+1, NUM2INT(rb_hash_aref(r, ID2SYM(rb_intern("ALLOCATE_INCREASE")))),
+		    NUM2INT(rb_hash_aref(r, ID2SYM(rb_intern("ALLOCATE_LIMIT")))),
+		    NUM2INT(rb_hash_aref(r, ID2SYM(rb_intern("HEAP_USE_SLOTS")))),
+		    rb_hash_aref(r, ID2SYM(rb_intern("HAVE_FINALIZE")))? "true" : "false",
+		    NUM2DBL(rb_hash_aref(r, ID2SYM(rb_intern("GC_MARK_TIME"))))*100,
+		    NUM2DBL(rb_hash_aref(r, ID2SYM(rb_intern("GC_SWEEP_TIME"))))*100);
+	    rb_str_concat(result, rb_str_new2(buf));
+	}
+#endif
+    }
+    return result;
+}
+
+
+/*
+ *  call-seq:
+ *     GC::Profiler.report
+ *
+ *  GC::Profiler.result display
+ *  
+ */
+
+VALUE
+gc_profile_report(int argc, VALUE *argv, VALUE self)
+{
+    VALUE out;
+
+    if (argc == 0) {
+	out = rb_stdout;
+    }
+    else {
+	rb_scan_args(argc, argv, "01", &out);
+    }
+    rb_io_write(out, gc_profile_result());
+
+    return Qnil;
+}
+
+
 /*
  *  The <code>GC</code> module provides an interface to Ruby's mark and
  *  sweep garbage collection mechanism. Some of the underlying methods
@@ -2451,6 +2781,7 @@ void
 Init_GC(void)
 {
     VALUE rb_mObSpace;
+    VALUE rb_mProfiler;
 
     rb_mGC = rb_define_module("GC");
     rb_define_singleton_method(rb_mGC, "start", rb_gc_start, 0);
@@ -2461,6 +2792,14 @@ Init_GC(void)
     rb_define_singleton_method(rb_mGC, "count", gc_count, 0);
     rb_define_method(rb_mGC, "garbage_collect", rb_gc_start, 0);
 
+    rb_mProfiler = rb_define_module_under(rb_mGC, "Profiler");
+    rb_define_singleton_method(rb_mProfiler, "enabled?", gc_profile_enable_get, 0);
+    rb_define_singleton_method(rb_mProfiler, "enable", gc_profile_enable, 0);
+    rb_define_singleton_method(rb_mProfiler, "disable", gc_profile_disable, 0);
+    rb_define_singleton_method(rb_mProfiler, "clear", gc_profile_clear, 0);
+    rb_define_singleton_method(rb_mProfiler, "result", gc_profile_result, 0);
+    rb_define_singleton_method(rb_mProfiler, "report", gc_profile_report, -1);
+
     rb_mObSpace = rb_define_module("ObjectSpace");
     rb_define_module_function(rb_mObSpace, "each_object", os_each_obj, -1);
     rb_define_module_function(rb_mObSpace, "garbage_collect", rb_gc_start, 0);