Make profiler for gc

narie$B$G$9!#e(B

GCe$BMQ$N%W%m%U%!%$%i$r:n$j$^$7$?!#e(B
e$BLdBj$,L5$1$l$P%3%_%C%H$7$?$N$G$9$,!"$$$+$,$G$7$g$&$+!)e(B


nari

Index: gc.c

— gc.c (e$B%j%S%8%g%se(B 18054)
+++ gc.c (e$B:n6H%3%T!<e(B)
@@ -179,6 +179,10 @@
struct gc_list *global_list;
unsigned int count;
int gc_stress;
+#if GC_PROFILE

  • gc_profile_data *gc_profile;
  • size_t gc_profile_size;
    +#endif
    } rb_objspace_t;

#if defined(ENABLE_VM_OBJSPACE) && ENABLE_VM_OBJSPACE
@@ -212,6 +216,11 @@

#define need_call_final (finalizer_table &&
finalizer_table->num_entries)

+#if GC_PROFILE
+#define gc_profile objspace->gc_profile
+#define gc_profile_size objspace->gc_profile_size
+#endif
+
#if defined(ENABLE_VM_OBJSPACE) && ENABLE_VM_OBJSPACE
rb_objspace_t *
rb_objspace_alloc(void)
@@ -1440,6 +1449,7 @@
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;
    @@ -1453,10 +1463,12 @@

    /* clear finalization list */
    if (final_list) {

  • GC_PROF_SET_INFO;
    deferred_final_list = final_list;
    return;
    }
    free_unused_heaps(objspace);

  • GC_PROF_SET_INFO;
    }

void
@@ -1672,6 +1684,7 @@
{
struct gc_list *list;
rb_thread_t *th = GET_THREAD();

  • INIT_GC_PROF_PARAMS;

    if (GC_NOTIFY) printf(“start garbage_collect()\n”);

@@ -1691,6 +1704,8 @@
during_gc++;
objspace->count++;

  • GC_PROF_TIMER_START;

  • GC_PROF_MARK_TIMER_START;
    SET_STACK_END;

    init_mark_stack(objspace);
    @@ -1731,9 +1746,13 @@
    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;
    }
    @@ -2386,6 +2405,36 @@
    }
    #endif

+#if GC_PROFILE
+VALUE
+gc_profile_report(void)
+{

  • VALUE prof = 0;
  • VALUE res = rb_hash_new();
  • VALUE datas = rb_ary_new();
  • size_t i;
  • rb_objspace_t *objspace = (&rb_objspace);
  • for (i =0; i < objspace->count; i++) {
  • prof = rb_hash_new();
  •    rb_hash_aset(prof, rb_str_new2("gc_time"),
    

DOUBLE2NUM(gc_profile[i]._gc_time));

  •    rb_hash_aset(prof, rb_str_new2("gc_mark_time"),
    

DOUBLE2NUM(gc_profile[i]._gc_mark_time));

  • rb_hash_aset(prof, rb_str_new2(“gc_sweep_time”),
    DOUBLE2NUM(gc_profile[i]._gc_sweep_time));
  •    rb_hash_aset(prof, rb_str_new2("heaps_used"),
    

rb_uint2inum(gc_profile[i]._heaps_used));

  •    rb_hash_aset(prof, rb_str_new2("live"),
    

rb_uint2inum(gc_profile[i]._live));

  •    rb_hash_aset(prof, rb_str_new2("freed"),
    

rb_uint2inum(gc_profile[i]._freed));

  •    rb_hash_aset(prof, rb_str_new2("heap_objects"),
    

rb_uint2inum(gc_profile[i]._heap_objects));

  •    rb_hash_aset(prof, rb_str_new2("is_exist_finalize"),
    

gc_profile[i]._is_exist_finalize);

  •    rb_hash_aset(prof, rb_str_new2("malloc_increase"),
    

rb_uint2inum(gc_profile[i]._malloc_increase));

  •    rb_hash_aset(prof, rb_str_new2("malloc_limit"),
    

rb_uint2inum(gc_profile[i]._malloc_limit));

  • rb_ary_push(datas, prof);
  • }
  • rb_hash_aset(res, rb_str_new2(“count”),
    rb_uint2inum(objspace->count));
  • rb_hash_aset(res, rb_str_new2(“report”), datas);
  • return res;
    +}
    +#endif

/*

  • The GC module provides an interface to Ruby’s mark and
  • sweep garbage collection mechanism. Some of the underlying methods
    @@ -2430,4 +2479,7 @@
    rb_define_singleton_method(rb_mGC, “malloc_allocated_size”,
    gc_malloc_allocated_size, 0);
    rb_define_singleton_method(rb_mGC, “malloc_allocations”,
    gc_malloc_allocations, 0);
    #endif
    +#if GC_PROFILE
  • rb_define_singleton_method(rb_mGC, “profile_report”,
    gc_profile_report, 0);
    +#endif
    }
    Index: gc.h
    ===================================================================
    — gc.h (e$B%j%S%8%g%se(B 18054)
    +++ gc.h (e$B:n6H%3%T!<e(B)
    @@ -72,4 +72,102 @@

define STACK_UPPER(x, a, b) (stack_growup_p(x) ? a : b)

#endif

+/* for GC profile */
+#define GC_PROFILE 0
+#if GC_PROFILE
+
+typedef struct gc_profile_data {

  • double _gc_time;
  • double _gc_mark_time;
  • double _gc_sweep_time;
  • size_t _heaps_used;
  • size_t _live;
  • size_t _freed;
  • size_t _heap_objects;
  • int _is_exist_finalize;
  • size_t _malloc_increase;
  • size_t _malloc_limit;
    +} gc_profile_data;

+static double
+cputime(void)
+{

  • struct timeval tv;
  • gettimeofday(&tv, NULL);
  • return tv.tv_sec + (double)tv.tv_usec*1e-6;
    +}

+#define INIT_GC_PROF_PARAMS double gc_time = 0, mark_time = 0,
sweep_time = 0;\

  • size_t count = objspace->count\

+#define GC_PROF_TIMER_START do {\

  • if (!gc_profile) {\
  •    gc_profile_size = 1000;\
    
  • gc_profile = malloc(sizeof(gc_profile_data) * gc_profile_size);\
  • }\
  • if (count >= gc_profile_size) {\
  •    gc_profile_size += 1000;\
    
  • gc_profile = realloc(gc_profile, sizeof(gc_profile_data) *
    gc_profile_size);\
  • }\
  • if (!gc_profile) {\
  • rb_bug(“gc_profile malloc or realloc miss”);\
  • }\
  • MEMZERO(&gc_profile[count], gc_profile_data, 1);\
  • gc_time = cputime();
    +} while(0)

+#define GC_PROF_TIMER_STOP do {\

  • gc_time = cputime() - gc_time;\
  • gc_profile[count]._gc_time = gc_time;
    +} while(0)

+#define GC_PROF_MARK_TIMER_START do {\

  • mark_time = cputime();
    +} while(0)

+#define GC_PROF_MARK_TIMER_STOP do {\

  • mark_time = cputime() - mark_time;\
  • gc_profile[count]._gc_mark_time = mark_time;
    +} while(0)

+#define GC_PROF_SWEEP_TIMER_START do {\

  • sweep_time = cputime();
    +} while(0)

+#define GC_PROF_SWEEP_TIMER_STOP do {\

  • sweep_time = cputime() - sweep_time;\
  • gc_profile[count]._gc_sweep_time = sweep_time;
    +} while(0)

+#define GC_PROF_SET_MALLOC_INFO do {\

  • size_t count = objspace->count - 1;\
  • gc_profile[count]._malloc_increase = malloc_increase;\
  • gc_profile[count]._malloc_limit = malloc_limit;
    +} while(0)

+#define GC_PROF_SET_INFO do {\

  • size_t count = objspace->count - 1;\
  • gc_profile[count]._heaps_used = heaps_used;\
  • gc_profile[count]._live = live;\
  • gc_profile[count]._freed = freed;\
  • gc_profile[count]._heap_objects = heaps_used * HEAP_OBJ_LIMIT;\
  • gc_profile[count]._is_exist_finalize = final_list ? Qtrue : Qfalse;

    +} while(0)

+#else
+#define INIT_GC_PROF_PARAMS
+#define GC_PROF_TIMER_START
+#define GC_PROF_TIMER_STOP
+#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_INFO
+#endif
+
+
#endif /* RUBY_GC_H */
+
+

narie$B$G$9!#e(B

e$BLdBj$,L5$1$l$P%3%%C%H$7$?$N$G$9$,!"$$$+$,$G$7$g$&$+!)e(B
e$B!V$$!W$r=q$-O3$l$^$7$?!#!#!#e(B
e$B!V%3%
%C%H$7$?$$$N$G$9$,!W$H$$$&0UL#$G$9!#e(B

e$B$9$_$^$;$s!"$h$m$7$/$*4j$$$7$^$9!#e(B


nari

2008/07/13 14:35 authorNari [email protected]:

e$B:XF#$H?=$7$^$9!#e(B

e$B<+J,$be(BGCe$B$K6=L#$,$“$k$N$G!”%W%m%U%!%$%i$,F~$C$?$i$&$l$7$$$G$9!#e(B
e$B$?$@!“%3%s%Q%$%k;~$K@EE*$K$=$NM-L5$,7h$^$C$F$7$^$&E@$O!”$A$g$C$H$d$j$E$i$$e(B
e$B$J$“!”$H46$8$^$9!#e(B(GC.stress=e$B$N$h$&$K!“e(BGC.profile=e$B$,$”$C$F$b$$$$$+$J$!!"$H$+!#e(B)

e$B$^$?!"$3$l$OHs>p$K:3:Y$J$3$H$J$N$G$9$,!"e(B

On Sun, 13 Jul 2008 14:35:13 +0900
authorNari [email protected] wrote:

  • size_t _malloc_limit;
    +} gc_profile_data;

e$B%a%s%PL>$,$3$H$4$H$/e(B _
e$B$G;O$^$C$F$$$kM}M3$O2?$J$N$G$7$g$&$+!#e(B
e$B<+J,$O$^$H$b$K%3!<%I%j!<%G%#%s%0$r$7$?$3$H$,$“$j$^$;$s$,!”>/$J$/$H$be(Bgc.ce$BFb$Ne(B
e$BB>$N2U=j$G$O!"F1MM$N%9%?%$%k$O8+$D$+$j$^$;$s$G$7$?!#e(B

In article
[email protected],
authorNari [email protected] writes:

GCe$BMQ$N%W%m%U%!%$%i$r:n$j$^$7$?!#e(B
e$BLdBj$,L5$1$l$P%3%_%C%H$7$?$N$G$9$,!"$$$+$,$G$7$g$&$+!)e(B

+static double
+cputime(void)
+{

  • struct timeval tv;
  • gettimeofday(&tv, NULL);

e$B%W%m%U%!%$%k$9$k$H$-$OEv3:%W%m%;%9$G>CHq$7$?;~4V$@$1$r7W$k$be(B
e$B$N$J$s$8$c$J$$$G$9$+!#e(B

narie$B$G$9!#e(B

e$B$_$J$5$s$4;XE&$"$j$,$H$&$4$6$$$^$9!#e(B
e$B%Q%C%A$r:n$jD>$7$^$7$?!#e(B

Index: gc.c

— gc.c (e$B%j%S%8%g%se(B 18055)
+++ gc.c (e$B:n6H%3%T!<e(B)
@@ -92,6 +92,103 @@

#undef GC_DEBUG

+/* for GC profile */
+#define GC_PROFILE 0
+#if GC_PROFILE
+
+typedef struct gc_profile_data {

  • double gc_time;
  • double gc_mark_time;
  • double gc_sweep_time;
  • size_t heaps_use_count;
  • size_t heaps_live;
  • size_t heaps_free;
  • size_t heaps_all_objects;
  • int is_exist_finalize;
  • size_t allocate_increase;
  • size_t allocate_limit;
    +} gc_profile_data;

+/* referenced document http://kzk9.net/column/time.html */
+static double
+getrusage_time(void)
+{

  • struct rusage usage;
  • struct timeval time;
  • getrusage(RUSAGE_SELF, &usage);
  • time = usage.ru_utime;
  • return time.tv_sec + (double)time.tv_usec*1e-6;
    +}

+#define INIT_GC_PROF_PARAMS double gc_time = 0, mark_time = 0,
sweep_time = 0;\

  • size_t count = objspace->count

+#define GC_PROF_TIMER_START do {\

  • if (!objspace->gc_profile) {\
  •    objspace->gc_profile_size = 1000;\
    
  • objspace->gc_profile = malloc(sizeof(gc_profile_data) *
    objspace->gc_profile_size);\
  • }\
  • if (count >= objspace->gc_profile_size) {\
  •    objspace->gc_profile_size += 1000;\
    
  • objspace->gc_profile = realloc(objspace->gc_profile,
    sizeof(gc_profile_data) * objspace->gc_profile_size);\
  • }\
  • if (!objspace->gc_profile) {\
  • rb_bug(“gc_profile malloc or realloc miss”);\
  • }\
  • MEMZERO(&objspace->gc_profile[count], gc_profile_data, 1);\
  • gc_time = getrusage_time();
    +} while(0)

+#define GC_PROF_TIMER_STOP do {\

  • gc_time = getrusage_time() - gc_time;\
  • objspace->gc_profile[count].gc_time = gc_time;
    +} while(0)

+#define GC_PROF_MARK_TIMER_START do {\

  • mark_time = getrusage_time();
    +} while(0)

+#define GC_PROF_MARK_TIMER_STOP do {\

  • mark_time = getrusage_time() - mark_time;\
  • objspace->gc_profile[count].gc_mark_time = mark_time;
    +} while(0)

+#define GC_PROF_SWEEP_TIMER_START do {\

  • sweep_time = getrusage_time();
    +} while(0)

+#define GC_PROF_SWEEP_TIMER_STOP do {\

  • sweep_time = getrusage_time() - sweep_time;\
  • objspace->gc_profile[count].gc_sweep_time = sweep_time;
    +} while(0)

+#define GC_PROF_SET_MALLOC_INFO do {\

  • size_t count = objspace->count - 1;\
  • objspace->gc_profile[count].allocate_increase = malloc_increase;\
  • objspace->gc_profile[count].allocate_limit = malloc_limit;
    +} while(0)

+#define GC_PROF_SET_HEAP_INFO do {\

  • size_t count = objspace->count - 1;\
  • objspace->gc_profile[count].heaps_use_count = heaps_used;\
  • objspace->gc_profile[count].heaps_live = live;\
  • objspace->gc_profile[count].heaps_free = freed;\
  • objspace->gc_profile[count].heaps_all_objects = heaps_used *
    HEAP_OBJ_LIMIT;\
  • objspace->gc_profile[count].is_exist_finalize = final_list ?
    Qtrue : Qfalse;
    +} while(0)

+#else
+#define INIT_GC_PROF_PARAMS
+#define GC_PROF_TIMER_START
+#define GC_PROF_TIMER_STOP
+#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
+#endif
+
#if defined(_MSC_VER) || defined(BORLANDC) || defined(CYGWIN)
#pragma pack(push, 1) /* magic for reducing sizeof(RVALUE): 24 → 20 */
#endif
@@ -179,6 +276,10 @@
struct gc_list *global_list;
unsigned int count;
int gc_stress;
+#if GC_PROFILE

  • gc_profile_data *gc_profile;
  • size_t gc_profile_size;
    +#endif
    } rb_objspace_t;

#if defined(ENABLE_VM_OBJSPACE) && ENABLE_VM_OBJSPACE
@@ -1440,6 +1541,7 @@
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;
    @@ -1453,10 +1555,12 @@

    /* clear finalization list */
    if (final_list) {

  • GC_PROF_SET_HEAP_INFO;
    deferred_final_list = final_list;
    return;
    }
    free_unused_heaps(objspace);

  • GC_PROF_SET_HEAP_INFO;
    }

void
@@ -1672,6 +1776,7 @@
{
struct gc_list *list;
rb_thread_t *th = GET_THREAD();

  • INIT_GC_PROF_PARAMS;

    if (GC_NOTIFY) printf(“start garbage_collect()\n”);

@@ -1691,6 +1796,8 @@
during_gc++;
objspace->count++;

  • GC_PROF_TIMER_START;

  • GC_PROF_MARK_TIMER_START;
    SET_STACK_END;

    init_mark_stack(objspace);
    @@ -1731,9 +1838,13 @@
    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;
    }
    @@ -2386,7 +2497,48 @@
    }
    #endif

+#if GC_PROFILE
+
/*

    • call-seq:
    • GC.profile_report -> hash
      
    • Report profile data.
    • It returns a hash as:
    • {:gc_count => 20 :report => [{:gc_time => 0.001, :gc_mark_time =>
      0.00004, :gc_sweep_time => 0.00006 }, … }]}
  • */

+VALUE
+gc_profile_report(void)
+{

  • VALUE prof = 0;
  • VALUE res = rb_hash_new();
  • VALUE datas = rb_ary_new();
  • size_t i;
  • rb_objspace_t *objspace = (&rb_objspace);
  • for (i =0; i < objspace->count; i++) {
  • prof = rb_hash_new();
  •    rb_hash_aset(prof, ID2SYM(rb_intern("gc_time")),
    

DOUBLE2NUM(objspace->profile.data[i].gc_time));

  •    rb_hash_aset(prof, ID2SYM(rb_intern("gc_mark_time")),
    

DOUBLE2NUM(objspace->profile.data[i].gc_mark_time));

  • rb_hash_aset(prof, ID2SYM(rb_intern(“gc_sweep_time”)),
    DOUBLE2NUM(objspace->profile.data[i].gc_sweep_time));
  •    rb_hash_aset(prof, ID2SYM(rb_intern("allocate_increase")),
    

rb_uint2inum(objspace->profile.data[i].allocate_increase));

  •    rb_hash_aset(prof, ID2SYM(rb_intern("allocate_limit")),
    

rb_uint2inum(objspace->profile.data[i].allocate_limit));

  •    rb_hash_aset(prof, ID2SYM(rb_intern("heaps_use_count")),
    

rb_uint2inum(objspace->profile.data[i].heaps_use_count));

  •    rb_hash_aset(prof, ID2SYM(rb_intern("heaps_live")),
    

rb_uint2inum(objspace->profile.data[i].heaps_live));

  •    rb_hash_aset(prof, ID2SYM(rb_intern("heaps_free")),
    

rb_uint2inum(objspace->profile.data[i].heaps_free));

  •    rb_hash_aset(prof, ID2SYM(rb_intern("heaps_all_objects")),
    

rb_uint2inum(objspace->profile.data[i].heaps_all_objects));

  •    rb_hash_aset(prof, ID2SYM(rb_intern("is_exist_finalize")),
    

objspace->profile.data[i].is_exist_finalize);

  • rb_ary_push(datas, prof);
  • }
  • rb_hash_aset(res, ID2SYM(rb_intern(“gc_count”)),
    rb_uint2inum(objspace->count));
  • rb_hash_aset(res, ID2SYM(rb_intern(“report”)), datas);
  • return res;
    +}
    +#endif

+/*

  • The GC module provides an interface to Ruby’s mark and
  • sweep garbage collection mechanism. Some of the underlying methods
  • are also available via the ObjectSpace module.
    @@ -2430,4 +2582,7 @@
    rb_define_singleton_method(rb_mGC, “malloc_allocated_size”,
    gc_malloc_allocated_size, 0);
    rb_define_singleton_method(rb_mGC, “malloc_allocations”,
    gc_malloc_allocations, 0);
    #endif
    +#if GC_PROFILE
  • rb_define_singleton_method(rb_mGC, “profile_report”,
    gc_profile_report, 0);
    +#endif
    }

2008/07/13 16:53 Tanaka A. [email protected]:

こんにちわ、nariです。

GCのプロファイラを少し改良してみました。

== 使用方法 ==
GC.profile = true

計測対象の処理

GC.display

---- ä»¥ä¸‹ã®ãƒ—ãƒ­ãƒ•ã‚¡ã‚¤ãƒ«æƒ…å ±ãŒå‡ºåŠ›ã•ã‚Œã‚‹ -----
GC 10 invokes.
Index Use Size(byte) Total Size(byte) Total Object
GC time(ms)
0 338620 360448 18018
0.00000000000000014129
1 605620 622592 31122
0.40010000000000001119
2 1080300 1097728 54873
0.00000000000000007657
3 1931420 1949696 97461
0.40000000000000018874
4 3470040 3489792 174447
0.40010000000000034426
5 6236220 6258688 312858
1.19999999999999906741
6 11212100 11239424 561834
2.00009999999999976694
7 20181760 20217856 1010646
3.60029999999999850147
8 36320600 36372480 1818180
6.80040000000000244285

2008275 used objects 80 free objects and 2008355 total objects in Heap.
Index Count % Kind (class)
1 1500000 74.68799092 Child
2 500000 24.89599697 Parent
3 5974 0.29745737 Object
4 1644 0.08185804 String
5 416 0.02071347 Class
6 81 0.00403315 Encoding
8 47 0.00234022
RubyVM::InstructionSequence
9 19 0.00094605 Module
10 17 0.00084646 Array
11 16 0.00079667 Hash
12 14 0.00069709 Float
13 10 0.00049792 Regexp
14 9 0.00044813 Enumerable
15 5 0.00024896 Comparable
16 3 0.00014938 IO
17 3 0.00014938 Precision
18 2 0.00009958 Bignum
19 1 0.00004979 Complex
20 1 0.00004979 Thread
21 1 0.00004979 RubyVM
22 1 0.00004979 ThreadGroup
23 1 0.00004979 NoMemoryError
24 1 0.00004979 Binding
25 1 0.00004979 SystemStackError
26 1 0.00004979 RubyVM::Env
27 1 0.00004979 Mutex
28 1 0.00004979 File::Constants
29 1 0.00004979 ARGF.class
30 1 0.00004979 Gem::QuickLoader
31 1 0.00004979 Data
32 1 0.00004979 fatal
33 1 0.00004979 Kernel
------ ここまで ------

== パッチを適用した際のメリット ==

  1. メモリリークの調査が簡単になる
      どのクラスが多く生成されているかよく分かり、調査しやすい。
      現在RubyレベルからHeapå†…éƒ¨ã®ã‚¯ãƒ©ã‚¹åã«ã‚ˆã‚‹çµ±è¨ˆæƒ…å ±ã‚’
      取得する方法は無く、これを提供する事によって、メモリリーク
      の調査がしやすくなる。

  2. パフォーマンスチューニングしやすい
      GCの実行時間を手軽に測れる、また、GCによるHeapサイズの
      変動を見ることができ、パフォーマンスチューニングがしやすく
      なる。

以上の2点が上げられるのではないかと思います。

もちろん、私がGCいじりやすくなってハッピーというのもありますが。。。

== è¿½åŠ ã•ã‚Œã‚‹ãƒ¡ã‚½ãƒƒãƒ‰ ==

  • GC.profile

  • GC.profile=
    ãƒ—ãƒ­ãƒ•ã‚¡ã‚¤ãƒ«ã‚’è¡Œã†å ´åˆã¯true, è¡Œã‚ãªã„å ´åˆfalse

  • GC.display
    ãƒ—ãƒ­ãƒ•ã‚¡ã‚¤ãƒ«æƒ…å ±ã€Heapã®è©³ç´°æƒ…å ±ã‚’å‡ºåŠ›

  • GC.count_classes
    => {:TOTAL => 3000000, :FREE => 30000, :String => 20000 … }
    ã€€ã€€ã‚¯ãƒ©ã‚¹åã§ã®çµ±è¨ˆæƒ…å ±ã‚’Hashにて取得可能

== パッチ ==
今回は少し大きめになったので、添付しておきます。

== ご意見など ==
åå‰ã¯ã“ã†ã—ãŸæ–¹ãŒã‚ˆã„ã¨ã‹ã€å‡ºåŠ›ã™ã‚‹æƒ…å ±ã¯ã‚‚ã£ã¨ã“ã†ã„ã†ã‚‚ã®ãŒã„ã„ã€
そもそもいらないのでは?などありましたら、ご意見いただけると嬉しい限りです。

それでは、よろしくお願いいたします。

2008/07/13 23:25 authorNari [email protected]:

narie$B$G$9!#e(B

e$B0lE@=q$-4V0c$$$,!#!#!#e(B

2008/07/17 22:38 authorNari [email protected]:

  • GC.count_classes
    => {:TOTAL => 3000000, :FREE => 30000, :String => 20000 … }
    e$B%/%i%9L>$G$NE}7W>pJs$re(BHashe$B$K$F<hF@2DG=e(B

GC.count_classes

e$B$G$O$J$/e(B

ObjectSpace.count_classes

e$B$G$7$?!#e(B

narie$B$G$9!#e(B

e$BF0E*$KJQ99$G$-$k%Q%C%A$bJ;$;$F:n@.$7$^$7$?!#e(B

e$B!Ve(BGC.profile=truee$B!W$G%W%m%U%!%$%k$7;O$a$F!"e(B
e$B!Ve(BGC.profile_reporte$B!W$G7k2L$rJV$7$F$/$l$^$9!#e(B

e$B$^$?!“DL>o$Oe(BGCe$BA4BN$N;~4V$N$_JV$7$^$9$,!”%3%s%Q%$%k;~$Ke(B
#define GC_PROFILE_MORE_DETAIL 1
e$B$K$9$k;v$Ge(Bmark/sweepe$B$K$+$+$C$?;~4VEy$N>:Y$J%G!<%?e(B
e$B$rJV$9$h$&$K$7$^$7$?!#e(B

e$BB.EYE*$K$b$=$lDx=E$/$J$$$h$&$G$9$7!";d$H$7$F$O$3$A$i$NJ}$,e(B
e$BNI$$$h$&$K;W$&$N$G$9$,$$$+$,$G$7$g$&$+!)e(B

e$B%Y%s%A%^!<%/e(B
normal profile
vm3_gc 2.359e$B!!!e(B 2.375

=============
nari@nari-laptop ~/s/r/ruby-trunk> make benchmark OPTS=“-r 10”
ruby ./benchmark/driver.rb -v
–executables=“ruby; ./miniruby -I./lib -I.ext/common
-I./- -r./ext/purelib.rb ./runruby.rb --extout=.ext --”
–pattern=‘bm_’ --directory=./benchmark -r 10
“1.9.0”
2008-07-13 22:42:41 +0900
target 0: ruby 1.9.0 (2008-07-11 revision 17780) [i686-linux]
target 1: ruby 1.9.0 (2008-07-13 revision 17780) [i686-linux]


vm3_gc

#! /usr/bin/ruby
5000.times do
100.times do
{“xxxx”=>“yyyy”}
end
GC.start
end

ruby 1.9.0 (2008-07-11 revision 17780) [i686-linux] 2.35910558700562
ruby 1.9.0 (2008-07-11 revision 17780) [i686-linux] 2.51446843147278
ruby 1.9.0 (2008-07-11 revision 17780) [i686-linux] 2.90153551101685
ruby 1.9.0 (2008-07-11 revision 17780) [i686-linux] 2.67432570457458
ruby 1.9.0 (2008-07-11 revision 17780) [i686-linux] 2.74260926246643
ruby 1.9.0 (2008-07-11 revision 17780) [i686-linux] 3.18074822425842
ruby 1.9.0 (2008-07-11 revision 17780) [i686-linux] 2.78490710258484
ruby 1.9.0 (2008-07-11 revision 17780) [i686-linux] 2.73308610916138
ruby 1.9.0 (2008-07-11 revision 17780) [i686-linux] 2.76204562187195
ruby 1.9.0 (2008-07-11 revision 17780) [i686-linux] 2.78759121894836
ruby 1.9.0 (2008-07-13 revision 17780) [i686-linux] 2.6268355846405
ruby 1.9.0 (2008-07-13 revision 17780) [i686-linux] 2.49695825576782
ruby 1.9.0 (2008-07-13 revision 17780) [i686-linux] 2.47115182876587
ruby 1.9.0 (2008-07-13 revision 17780) [i686-linux] 2.37481427192688
ruby 1.9.0 (2008-07-13 revision 17780) [i686-linux] 2.85433769226074
ruby 1.9.0 (2008-07-13 revision 17780) [i686-linux] 2.76230645179749
ruby 1.9.0 (2008-07-13 revision 17780) [i686-linux] 2.74803757667542
ruby 1.9.0 (2008-07-13 revision 17780) [i686-linux] 2.48261618614197
ruby 1.9.0 (2008-07-13 revision 17780) [i686-linux] 2.42063546180725
ruby 1.9.0 (2008-07-13 revision 17780) [i686-linux] 2.67150807380676


raw data:

[[“vm3_gc”,
[[2.35910558700562,
2.51446843147278,
2.90153551101685,
2.67432570457458,
2.74260926246643,
3.18074822425842,
2.78490710258484,
2.73308610916138,
2.76204562187195,
2.78759121894836],
[2.6268355846405,
2.49695825576782,
2.47115182876587,
2.37481427192688,
2.85433769226074,
2.76230645179749,
2.74803757667542,
2.48261618614197,
2.42063546180725,
2.67150807380676]]]]

Elapesed time: 53.357572675 (sec)

benchmark results:
minimum results in each 10 measurements.
name ruby 1.9.0 (2008-07-11 revision 17780) [i686-linux] ruby 1.9.0
(2008-07-13 revision 17780) [i686-linux]
vm3_gc 2.359 2.375

Index: gc.c

— gc.c (e$B%j%S%8%g%se(B 18054)
+++ gc.c (e$B:n6H%3%T!<e(B)
@@ -92,6 +92,117 @@

#undef GC_DEBUG

+/* for GC profile */
+#define GC_PROFILE_MORE_DETAIL 0
+typedef struct gc_profile_data {

  • double gc_time;
  • double gc_mark_time;
  • double gc_sweep_time;
  • size_t heaps_use_count;
  • size_t heaps_live;
  • size_t heaps_free;
  • size_t heaps_all_objects;
  • int is_exist_finalize;
  • size_t allocate_increase;
  • size_t allocate_limit;
    +} gc_profile_data;

+/* referenced document http://kzk9.net/column/time.html */
+static double
+getrusage_time(void)
+{

  • struct rusage usage;
  • struct timeval time;
  • getrusage(RUSAGE_SELF, &usage);
  • time = usage.ru_utime;
  • return time.tv_sec + (double)time.tv_usec*1e-6;
    +}

+#define GC_PROF_TIMER_START do { \

  • if (ruby_gc_profile) { \
  •  if (!objspace->profile.data) {        \
    
  • objspace->profile.size = 1000; \
  • objspace->profile.data = malloc(sizeof(gc_profile_data) *
    objspace->profile.size); \
  •  }                \
    
  •  if (count >= objspace->profile.size) {      \
    
  • objspace->profile.size += 1000; \
  • objspace->profile.data = realloc(objspace->profile.data,
    sizeof(gc_profile_data) * objspace->profile.size); \
  •  }                \
    
  •  if (!objspace->profile.data) {        \
    
  • rb_bug(“gc_profile malloc or realloc miss”); \
  •  }                \
    
  •  MEMZERO(&objspace->profile.data[count], gc_profile_data, 1); \
    
  •  gc_time = getrusage_time();          \
    
  • } \
  • } while(0)

+#define GC_PROF_TIMER_STOP do { \

  • if (ruby_gc_profile) { \
  •  gc_time = getrusage_time() - gc_time;    \
    
  •  objspace->profile.data[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 (ruby_gc_profile) { \
  •  mark_time = getrusage_time();  \
    
  • } \
  • } while(0)

+#define GC_PROF_MARK_TIMER_STOP do { \

  • if (ruby_gc_profile) { \
  •  mark_time = getrusage_time() - mark_time;      \
    
  •  objspace->profile.data[count].gc_mark_time = mark_time;  \
    
  • } \
  • } while(0)

+#define GC_PROF_SWEEP_TIMER_START do { \

  • if (ruby_gc_profile) { \
  •  sweep_time = getrusage_time();  \
    
  • } \
  • } while(0)

+#define GC_PROF_SWEEP_TIMER_STOP do { \

  • if (ruby_gc_profile) { \
  •  sweep_time = getrusage_time() - sweep_time;      \
    
  •  objspace->profile.data[count].gc_sweep_time = sweep_time;  \
    
  • } \
  • } while(0)
    +#define GC_PROF_SET_MALLOC_INFO do { \
  • if (ruby_gc_profile) { \
  •  size_t count = objspace->profile.count;      \
    
  •  objspace->profile.data[count].allocate_increase = 
    

malloc_increase; \

  •  objspace->profile.data[count].allocate_limit = malloc_limit; \
    
  • } \
  • } while(0)
    +#define GC_PROF_SET_HEAP_INFO do { \
  • if (ruby_gc_profile) { \
  •  size_t count = objspace->profile.count;      \
    
  •  objspace->profile.data[count].heaps_use_count = heaps_used;  \
    
  •  objspace->profile.data[count].heaps_live = live;    \
    
  •  objspace->profile.data[count].heaps_free = freed;    \
    
  •  objspace->profile.data[count].heaps_all_objects = heaps_used *
    

HEAP_OBJ_LIMIT; \

  •  objspace->profile.data[count].is_exist_finalize = final_list ?
    

Qtrue : Qfalse; \

  • } \
  • } 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
    +#endif

#if defined(_MSC_VER) || defined(BORLANDC) || defined(CYGWIN)
#pragma pack(push, 1) /* magic for reducing sizeof(RVALUE): 24 → 20 */
#endif
@@ -176,6 +287,12 @@
VALUE *ptr;
int overflow;
} markstack;

  • struct {
  • int run;
  • gc_profile_data *data;
  • size_t count;
  • size_t size;
  • } profile;
    struct gc_list *global_list;
    unsigned int count;
    int gc_stress;
    @@ -209,6 +326,7 @@
    #define mark_stack_overflow objspace->markstack.overflow
    #define global_List objspace->global_list
    #define ruby_gc_stress objspace->gc_stress
    +#define ruby_gc_profile objspace->profile.run

#define need_call_final (finalizer_table &&
finalizer_table->num_entries)

@@ -309,6 +427,46 @@
return bool;
}

+/*

    • call-seq:
    • GC.profile => true or false
    • returns current status of GC profile mode.
  • */

+static VALUE
+gc_profile_get(VALUE self)
+{

  • rb_objspace_t *objspace = &rb_objspace;
  • return ruby_gc_profile ? Qtrue : Qfalse;
    +}

+/*

    • call-seq:
    • GC.profile = bool => bool
    • updates GC profile mode.
    • When GC.profile = true, run profiler for GC.
    • When GC.profile = false, delete before profiler data.
    • if want more detail info. please use GC_PROFILE_MORE_DETAIL.
  • */

+static VALUE
+gc_profile_set(VALUE self, VALUE bool)
+{

  • rb_objspace_t *objspace = &rb_objspace;
  • rb_secure(2);
  • ruby_gc_profile = RTEST(bool);
  • if (!ruby_gc_profile) {
  • MEMZERO(objspace->profile.data, gc_profile_data,
    objspace->profile.size);
  • objspace->profile.count = 0;
  • }
  • return bool;
    +}

static void *
vm_xmalloc(rb_objspace_t *objspace, size_t size)
{
@@ -1440,6 +1598,7 @@
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;
    @@ -1453,10 +1612,12 @@

    /* clear finalization list */
    if (final_list) {

  • GC_PROF_SET_HEAP_INFO;
    deferred_final_list = final_list;
    return;
    }
    free_unused_heaps(objspace);

  • GC_PROF_SET_HEAP_INFO;
    }

void
@@ -1672,6 +1833,7 @@
{
struct gc_list *list;
rb_thread_t *th = GET_THREAD();

  • INIT_GC_PROF_PARAMS;

    if (GC_NOTIFY) printf(“start garbage_collect()\n”);

@@ -1691,6 +1853,8 @@
during_gc++;
objspace->count++;

  • GC_PROF_TIMER_START;

  • GC_PROF_MARK_TIMER_START;
    SET_STACK_END;

    init_mark_stack(objspace);
    @@ -1731,9 +1895,13 @@
    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;
    }
    @@ -2387,6 +2555,53 @@
    #endif

/*

    • call-seq:
    • GC.profile_report -> hash
      
    • Report profile data to wrap hash.
    • It returns a hash as:
    • {:gc_count => 20 :report => [{:gc_time => 0.001}, {:gc_time =>
      0.002}]}
    • if GC_PROFILE_MORE_DETAIL is 1:
    • {:gc_count => 20 :report => [{:gc_time => 0.001, :gc_mark_time =>
      0.00004, :gc_sweep_time => 0.00006 }, … }]}
  • */

+VALUE
+gc_profile_report(void)
+{

  • VALUE prof = 0;
  • VALUE res = rb_hash_new();
  • VALUE datas = rb_ary_new();
  • size_t i;
  • rb_objspace_t *objspace = (&rb_objspace);
  • if (!ruby_gc_profile) {
  • 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.data[i].gc_time));
+#if GC_PROFILE_MORE_DETAIL

  •    rb_hash_aset(prof, ID2SYM(rb_intern("gc_mark_time")),
    

DOUBLE2NUM(objspace->profile.data[i].gc_mark_time));

  • rb_hash_aset(prof, ID2SYM(rb_intern(“gc_sweep_time”)),
    DOUBLE2NUM(objspace->profile.data[i].gc_sweep_time));
  •    rb_hash_aset(prof, ID2SYM(rb_intern("allocate_increase")),
    

rb_uint2inum(objspace->profile.data[i].allocate_increase));

  •    rb_hash_aset(prof, ID2SYM(rb_intern("allocate_limit")),
    

rb_uint2inum(objspace->profile.data[i].allocate_limit));

  •    rb_hash_aset(prof, ID2SYM(rb_intern("heaps_use_count")),
    

rb_uint2inum(objspace->profile.data[i].heaps_use_count));

  •    rb_hash_aset(prof, ID2SYM(rb_intern("heaps_live")),
    

rb_uint2inum(objspace->profile.data[i].heaps_live));

  •    rb_hash_aset(prof, ID2SYM(rb_intern("heaps_free")),
    

rb_uint2inum(objspace->profile.data[i].heaps_free));

  •    rb_hash_aset(prof, ID2SYM(rb_intern("heaps_all_objects")),
    

rb_uint2inum(objspace->profile.data[i].heaps_all_objects));

  •    rb_hash_aset(prof, ID2SYM(rb_intern("is_exist_finalize")),
    

objspace->profile.data[i].is_exist_finalize);
+#endif

  • rb_ary_push(datas, prof);
  • }
  • rb_hash_aset(res, ID2SYM(rb_intern(“gc_count”)),
    rb_uint2inum(objspace->count));
  • rb_hash_aset(res, ID2SYM(rb_intern(“report”)), datas);
  • return res;
    +}

+/*

  • The GC module provides an interface to Ruby’s mark and
  • sweep garbage collection mechanism. Some of the underlying methods
  • are also available via the ObjectSpace module.
    @@ -2404,6 +2619,9 @@
    rb_define_singleton_method(rb_mGC, “stress”, gc_stress_get, 0);
    rb_define_singleton_method(rb_mGC, “stress=”, gc_stress_set, 1);
    rb_define_singleton_method(rb_mGC, “count”, gc_count, 0);
  • rb_define_singleton_method(rb_mGC, “profile”, gc_profile_get, 0);

  • rb_define_singleton_method(rb_mGC, “profile=”, gc_profile_set, 1);

  • rb_define_singleton_method(rb_mGC, “profile_report”,
    gc_profile_report, 0);
    rb_define_method(rb_mGC, “garbage_collect”, rb_gc_start, 0);

    rb_mObSpace = rb_define_module(“ObjectSpace”);

e$B?\F#$G$9!#e(B

e$BL>A0$@$1$G$9$,!#!#!#e(B

In [email protected]
“[ruby-dev:35568] Re: make profiler for gc” on Thu, 17 Jul 2008
22:38:53 +0900,
authorNari [email protected] wrote:

== e$BDI2C$5$l$k%a%=%C%Ie(B ==

  • GC.profile
  • GC.profile=
    e$B%W%m%U%!%$%k$r9T$&>l9g$Oe(Btrue, e$B9T$o$J$$>l9ge(Bfalse

e$B??56CM$rJV$9$N$G$"$l$Pe(B?e$B$r$D$1$?J}$,$h$$$H;W$$$^$9!#$?$@!“e(B
GC.profile?e$B$H$$$&$N$O$”$^$j%T%s$H$3$J$$5$$,$7$^$9$,!#!#!#e(B
e$B$H$$$&$+e(BGC.stresse$B$be(B?e$B$J$7$@$C$?$s$G$9$M!#e(B

  • GC.display
    e$B%W%m%U%!%$%k>pJs!"e(BHeape$B$N>:Y>pJs$r=PNOe(B

GC.displaye$B$+$i!V%W%m%U%!%$%k>pJs$r=PNO$9$k!W$H$$$&$N$OM=A[$7e(B
e$B$E$i$$5$$,$7$^$9!#e(BGC.reporte$B$,$h$$$+$H;W$C$?$N$G$9$,!";H$o$le(B
e$B$F$$$^$9$M!#e(B

e$B8D?ME*$K$O$3$s$JJ}$,9%$_$G$9!#e(B

  • GC::Profiler.enable?
  • GC::Profiler.enable
  • GC::Profiler.disable
  • GC::Profiler.format # GC.displaye$BAjEv$rJ8;zNs$GJV$9e(B
  • GC::Profiler.report # formate$B$r=PNOe(B
  • GC::Profiler.data # GC.report

e$B!!$5$5$@$G$9!%e(B

authorNari wrote:

==e$BDI2C$5$l$k%a%=%C%Ie(B

  • GC::Profiler.enable?
    ** Profilere$B$,5/F0$7$F$$$k$+!)e(B
  • GC::Profiler.enable=
    ** Profilere$B5/F0e(B true false

enable= / enable? e$B$N%Z%"$O$J$$$H;W$$$^$9$h!%e(B

nariです。

個人的にはこんな方が好みです。

  • GC::Profiler.enable?
  • GC::Profiler.enable
  • GC::Profiler.disable
  • GC::Profiler.format # GC.display相当を文字列で返す
  • GC::Profiler.report # formatを出力
  • GC::Profiler.data # GC.report

おぉ、すごく分かりやすい名前だと思います。
ということで早速変更してみました。

==è¿½åŠ ã•ã‚Œã‚‹ãƒ¢ã‚¸ãƒ¥ãƒ¼ãƒ«

  • GC::Profiler
    **GCにおけるProfileæƒ…å ±ã‚’æ‰±ã†

==è¿½åŠ ã•ã‚Œã‚‹ãƒ¡ã‚½ãƒƒãƒ‰

  • GC::Profiler.enable?
    ** Profilerが起動しているか?
  • GC::Profiler.enable=
    ** Profilerèµ·å‹• true false
  • GC::Profiler.disable=
    ** Profiler停止 true false
  • GC::Profiler.format
    ** ãƒ—ãƒ­ãƒ•ã‚¡ã‚¤ãƒ«æƒ…å ±ã€Heapã®è©³ç´°æƒ…å ±ã®æ–‡å­—åˆ—è¿”å´
    *** (この前のメールのGC.dispalyで出力されるものが文字列で返ってくる)
  • GC::Profiler.report
    ** GC::Profiler.formatの文字列出力
  • GC::Prifler.data
    ** GC::Profiler.displayで表示する元データをHashで返却

その他のメソッドについては先のメールと同じ

==パッチ
今回も添付しています。

と言う事でよさそうだったらコミットしたいのですが、いかがでしょうか?

e$B;01:$H?=$7$^$9!#e(B
e$BCY$$H?1~$G?=$7Lu$"$j$^$;$s!#e(B

profiler for gce$B$K$D$$$FMWK>$,e(B2e$BE@$"$j$^$9!#e(B

e$B$=$N#1e(B

GC::Profile.report, GC::Profile.datae$B$GF@$i$l$kNrBe$Ne(BGC
e$B$N%m%0>pJs$r%/%j%"$9$k%a%=%C%Ie(Bcleare$B!J2>>Ne(B)e$B$,$"$k$H$$$$e(B
e$B$J$H;W$$$^$9!#e(B
e$B$h$C$]$ID9$$;~4V<B9T$7$J$$$H!"%m%0>pJs$G%a%b%j$r05Gwe(B
e$B$9$k$3$H$OL5$$$H;W$$$^$9$,!":YJ,2=$7$?%R!<%WNN0h$,e(B
e$B%m%0>pJs$@$1$N$?$a$K2rJ|$G$-$J$$$H$$$&>u67$,e(B
e$B$"$j$($k$+$J$H;W$$$^$9!#e(B
e$B%m%0>pJs$r%P%C%0%0%i%&%s%I$GF0$/%9%l%C%IEy$G%U%!%$%k$Ke(B
e$B=q$-=P$7$?$i$3$N%a%=%C%I$r<B9T$7$F%a%b%j$r2rJ|$9$k$H$$$&e(B
e$B46$8$G;H$&$3$H$r9M$($F$$$^$9!#e(B

e$B<B9TNce(B

GC::Profile.report
GC::Profile.clear
puts “e$B$/$j$”!e(B"
GC::Profile.report
puts "e$B$
$o$j!*e(B"

e$B=PNONce(B
GC 10 invokes.
Index Use Size(byte) Total Size(byte) Total Object
GC time(ms)
0 338620 360448 18018
0.00000000000000014129
1 605620 622592 31122
0.40010000000000001119
2 1080300 1097728 54873
0.00000000000000007657
3 1931420 1949696 97461
0.40000000000000018874

e$B$/$j$"!e(B
GC 10 invokes.
Index Use Size(byte) Total Size(byte) Total Object
GC time(ms)
e$B$
$o$j!*e(B

e$B$=$N#2e(B

GCe$B$r<B9T$7$?4V3V$bI=<($7$FM_$7$$!#e(B

GCe$B$,$I$l$@$1$N;~4V3]$+$C$?$+$N>pJs$@$1$G$O$J$/!“A02s$Ne(BGC
e$B$+$i$I$l$@$17P$C$F$+$ie(BGCe$B$,5/F0$5$l$?$+J,$+$k$H!”$$$m$$$me(B
e$B$&$l$7$$e(B(e$B%R!<%W%5%$%:$rD4@0$7$F$_$h$&$H5$$E$/$H$+e(B)e$B$8$c$J$$$+$Je(B
e$B$H;W$$$^$9!#e(B

nariです。

2008/07/19 13:01 SASADA Koichi [email protected]:


// SASADA Koichi at atdot dot net

すみません。
é ˆè—¤ã•ã‚“ã®ãƒ¡ãƒ¼ãƒ«ã‚’èª­ã¿é•ãˆã¦ã„ã¾ã—ãŸã€‚

  • GC::Profiler.enable
    ** Profilerèµ·å‹•
  • GC::Profiler.disable
    ** Profiler停止

に修正しました。

失礼しました。


nari

narie$B$G$9!#e(B

e$B$3$N7o$K4X$7$F!":rF|$^$D$b$H$5$s$KD>@?R$M$F$_$?=j!"e(B
e$B!VF~$l$k$3$H$K$O;?@.$@$1$I!“5$$K$J$kE@$,?tE@$”$k!We(B
e$B$H2sEz$rD:$-$^$7$?!#e(B
e$B0J2<$O$=$NFbMF$HBP1~$G$9!#e(B

== ObjectSpace.count_classese$B$K$D$$$Fe(B

  • e$BL>A0$,5$$K$J$ke(B
    ->e$B?’!9$H9M$($F$_$^$7$?!#e(B

    • count_by_classname
    • destribution_map
    • layout
    • statistic
      e$B;dE*$K$Oe(B"ObjectSpace.statistic"e$B$,$$$$$H;W$&$N$G$9$,$$$+$,$G$7$g$&!)e(B
  • e$B%M%9%H$5$l$?%/%i%9L>$,I=<($5$l$J$$e(B
    ->e$B=$@5$7$^$7$?e(B

  • e$B%/%i%9L>$,%7%s%%k$K$J$C$F5"$C$F$-$F$k$N$GJ8;zNs$,$$$$e(B
    ->e$B=$@5$7$^$7$?e(B

== GC::Profiler.formate$B$K$D$$$Fe(B

  • e$BL>A0$,$A$g$C$He(B
    ->e$BA0ED$5$s$N0F$rD:$$$Fe(B"GC::Profiler.result"e$B$KJQ99$7$^$7$?!#e(B

== GC::Profiler.datae$B$K$D$$$Fe(B
*
e$B5$;}$A$OJ,$+$k$1$I!"@8%G!<%?$,BgNL$K5"$C$F$/$k$N$O$A$g$H5$;}$A0-$$!#e(B
e$B:#2s$O30$@$7$K$7$J$$J}$,$$$$$+$b!#e(B
->datae$B$O$"$s$^$j$JL>A0$@$J$H;W$C$F!"e(B"GC::Profiler.record"e$B$H$$$&L>A0$KJQ99$7$^$7$?!#e(B
->e$B30$@$7$O8+Aw$j$^$7$?!#e(B

e$B:#2s$N=$@5$r2C$($F!":#$^$G$N5!G=$r$^$H$a$k$H0J2<$N$h$&$K$J$j$^$9!#e(B

== module,method

  • GC::Profiler
    Profilere$BMQ$N%b%8%e!<%ke(B

  • GC::Profiler.enable?
    e$B8=:_$N%9%F!<%?%9$rJV5Qe(B

  • GC::Profiler.enable
    Profilere$B$rM-8z2=e(B

  • GC::Profiler.disable
    Profilere$B$rL58z2=e(B

  • GC::Profiler.clear
    Profilere$B$K$FJ];}$7$F$$$?%G!<%?$r:o=|e(B

  • GC::Profiler.report
    Profilee$B7k2LI=<(e(B

  • GC::Profiler.result
    Profilee$B7k2L$rJ8;zNs$GJV5Qe(B

  • ObjectSpace.statistic
    ObjectSpacee$BFb$NE}7W$r<h$j$^$9!#e(B
    e$BLa$jCMe(B :
    {:TOTAL=>10000, :FREE=>3011, :String=>6, :Array=>404, …}

e$B$$$+$,$G$7$g$&$+!)e(B

nariです。

貴重なご意見ありがとうございます。

profiler for gcについて要望が2点あります。

その1

GC::Profile.report, GC::Profile.dataで得られる歴代のGC
ã®ãƒ­ã‚°æƒ…å ±ã‚’ã‚¯ãƒªã‚¢ã™ã‚‹ãƒ¡ã‚½ãƒƒãƒ‰clear(仮称)があるといい
なと思います。

そうですね。
確かにclearはあると良さそうです。

その2

GCを実行した間隔も表示して欲しい。
この辺、Javaはどうやっているのかなと思って調べてみました。

http://www.atdot.net/sp/readonly/6mee4k

この様な形でGC起動の間隔を知ることができるようです。
#ã€€ãã®ä»–ã®å–å¾—æ–¹æ³•ç­‰ã‚ã‚Œã°æŒ‡æ‘˜ã—ã¦é ‚ã‘ã‚‹ã¨åŠ©ã‹ã‚Šã¾ã™

確かに間隔も表示されれば良さそうですね。

==変更対象

  • GC::Profiler.clear
    ** 追åŠ

  • GC::Profiler.data
    ** Hashã®è¦ç´ ã«[:GC_INVOKE_TIME] 追åŠ

  • GC::Profiler.format
    ** Invoke Time(sec)の列を追åŠ

==å‡ºåŠ›ã•ã‚Œã‚‹ãƒ—ãƒ­ãƒ•ã‚¡ã‚¤ãƒ«æƒ…å ±

GC 12 invokes.
Index Invoke Time(sec) Use Size(byte) Total Size(byte) Total Object GC
time(ms)
1 0.020 338260 360448 18018 0.00000000000000011486
2 0.032 605640 622592 31122 0.40000000000000024425
3 0.056 1080320 1097728 54873 0.40000000000000002220
4 0.080 1931460 1949696 97461 0.80000000000000037748
5 0.124 3470040 3489792 174447 0.40010000000000017772
6 0.196 6236240 6258688 312858 1.20009999999999994458
7 0.324 11212120 11239424 561834 2.00010000000000065512
8 0.552 20181780 20217856 1010646 4.00029999999999485993
9 0.960 36320640 36372480 1818180 6.80040000000000954827
10 1.904 46802400 65437696 3271086 11.20070000000001009255
11 2.644 65373820 65454080 3271905 13.60079999999998712212

==パッチ
今回も添付しておきます。

他にもご意見等あれば、教えていただけると助かります。

e$B$^$D$b$He(B e$B$f$-$R$m$G$9e(B

In message “Re: [ruby-dev:35803] Re: make profiler for gc”
on Sat, 9 Aug 2008 17:12:06 +0900, Narihiro N.
[email protected] writes:

|e$B$3$N7o$K4X$7$F!":rF|$^$D$b$H$5$s$KD>@?R$M$F$_$?=j!"e(B
|e$B!VF~$l$k$3$H$K$O;?@.$@$1$I!“5$$K$J$kE@$,?tE@$”$k!We(B
|e$B$H2sEz$rD:$-$^$7$?!#e(B
|e$B0J2<$O$=$NFbMF$HBP1~$G$9!#e(B

e$B$I$b$G$9!#e(B

|e$B:#2s$N=$@5$r2C$($F!":#$^$G$N5!G=$r$^$H$a$k$H0J2<$N$h$&$K$J$j$^$9!#e(B
|
|== module,method
|* GC::Profiler
|Profilere$BMQ$N%b%8%e!<%ke(B
|
|* GC::Profiler.enable?
|e$B8=:_$N%9%F!<%?%9$rJV5Qe(B
|
|* GC::Profiler.enable
|Profilere$B$rM-8z2=e(B
|
|* GC::Profiler.disable
|Profilere$B$rL58z2=e(B
|
|* GC::Profiler.clear
|Profilere$B$K$FJ];}$7$F$$$?%G!<%?$r:o=|e(B
|
|* GC::Profiler.report
|Profilee$B7k2LI=<(e(B
|
|* GC::Profiler.result
|Profilee$B7k2L$rJ8;zNs$GJV5Qe(B
|
|* ObjectSpace.statistic
|ObjectSpacee$BFb$NE}7W$r<h$j$^$9!#e(B
|e$BLa$jCMe(B :
|{:TOTAL=>10000, :FREE=>3011, :String=>6, :Array=>404, …}
|
|e$B$$$+$,$G$7$g$&$+!)e(B

e$B$$$$$s$8$c$J$$$+$H;W$$$^$9$,!“$3$l$@$He(Bstatistice$B$N%-!<$O$”$$$+e(B
e$B$o$i$:e(BSymbole$B$K$J$C$F$^$9$M!#$9$G$K;XE&$7$?$h$&$K%M%9%H$7$?%/e(B
e$B%i%9$KBP1~$9$k$?$a!“$3$3$Oe(BClasse$B$=$N$b$N$+!”$"$k$$$OJ8;zNs$,%-!<e(B
e$B$K$J$k$Y$-$G$O$J$$$+$H;W$$$^$9!#e(B

                            e$B$^$D$b$He(B e$B$f$-$R$me(B /:|)

e$B9bHx9(<#$G$9!#e(B

On 2008/08/09, at 17:12, Narihiro N. wrote:

e$B:#2s$N=$@5$r2C$($F!":#$^$G$N5!G=$r$^$H$a$k$H0J2<$N$h$&$K$J$j$^$9!#e(B

== module,method
(e$B>JN,e(B)

  • GC::Profiler.enable?
    e$B8=:_$N%9%F!<%?%9$rJV5Qe(B

e$B$3$l$O!"e(Bnari e$B$/$s$r4^$a!"D>@\OC$r$7$?$H$-$Ke(B
GC::Profiler.enabled? e$B$H$$$&0F$b$G$?$N$G$9$,!"e(B
e$B$I$&$G$7$g$&$+$M!#e(B

nariです。

返信ありがとうございます。

Yukihiro M. さんは書きました:

いいんじゃないかと思いますが、これだとstatisticのキーはあいか
わらずSymbolになってますね。すでに指摘したようにネストしたク
ラスに対応するため、ここはClassそのものか、あるいは文字列がキー
になるべきではないかと思います。

すみません。うっかりしていました。
その様に修正します。

Takao K. さんは書きました:

これは、nari くんを含め、直接話をしたときに
GC::Profiler.enabled? という案もでたのですが、
どうでしょうかね。

すみません、これはruby-coreでも指摘された点で、
すでに手元では修正済みだったのでした。

æŒ‡æ‘˜ã‚’é ‚ã„ãŸç‚¹ã‚’ä¿®æ­£ã—ã¾ã—ãŸã€‚

== module,method

  • GC::Profiler
    Profiler用のモジュール

  • GC::Profiler.enabled?
    現在のステータスを返却

  • GC::Profiler.enable
    Profilerを有効化

  • GC::Profiler.disable
    Profilerを無効化

  • GC::Profiler.clear
    Profilerにて保持していたデータを削除

  • GC::Profiler.report
    Profile結果表示

  • GC::Profiler.result
    Profile結果を文字列で返却

  • ObjectSpace.statistic
    ObjectSpace内の統計を取ります。
    戻り値 :
    {:TOTAL=>10000, :FREE=>3011, “Foo::Bar”=>6, “Array”=>404, …}

今回添付したパッチで問題なければコミットしたいと思います。

narie$B$G$9!#e(B

OZAWA Sakuro e$B$5$s$O=q$-$^$7$?e(B:

e$B$5$/$G$9!#e(B

statistice$B$OC1?t7A$G$h$$$N$G$7$g$&$+e(B?

e$BE}7W3X$H$$$&0UL#0J30$K$b!"E}7W;qNAE*$J0UL#9g$$$G$OJ#?t7A$GMQ$$$k$h$&$G$9!#e(B
e$BC1?t$@$H%5%s%W%j%s%0$K$*$1$k!V%5%s%W%ke(B1e$B$D!W$K6a$$$h$&$J!#e(B

e$B$4;XE&$"$j$,$H$&$4$6$$$^$9!#e(B

statistics on ObjectSpace
e$B$NMM$J0UL#9g$$$K$J$k$H;W$$$^$9$N$G!"e(B
e$B3N$+$Ke(Bstatisticse$B!JJ#?t7A!K$NJ}$,$U$5$o$7$=$&$G$9$M!#e(B

e$B=$@5$7$F$*$-$^$9!#e(B

narie$B$G$9!#e(B

e$B$^$D$b$H$5$s$K5v2D$rD:$$$?$N$G%3%_%C%H$7$^$7$?!#e(B

e$B:G=E$K0J2<$NMM$KMn$ACe$-$^$7$?!#e(B

== module,method

  • GC::Profiler
    Profilere$BMQ$N%b%8%e!<%ke(B

  • GC::Profiler.enabled?
    e$B8=:_$N%9%F!<%?%9$rJV5Qe(B

  • GC::Profiler.enable
    Profilere$B$rM-8z2=e(B

  • GC::Profiler.disable
    Profilere$B$rL58z2=e(B

  • GC::Profiler.clear
    Profilere$B$K$FJ];}$7$F$$$?%G!<%?$r:o=|e(B

  • GC::Profiler.report
    Profilee$B7k2LI=<(e(B

  • GC::Profiler.result
    Profilee$B7k2L$rJ8;zNs$GJV5Qe(B

ObjectSpace.statsticse$B$G$9$,!":#2s$OF~$l$J$$;v$K$7$^$7$?!#e(B
e$BM}M3$O0J2<$G$9!#e(B

ObjectSpace.statsticse$B=hM}Fb$Ge(BGCe$B$,H/@8$9$k2DG=@-$,$"$j4m81$J$?$ae(B
2. ObjectSpace.each_objecte$B$r;H$($P%f!<%6!<%l%Y%k$G<BAu2DG=$J$?$ae(B

e$B4|BT$7$F$$$?J}$4$a$s$J$5$$!J$$$k$N$+$J!#!#!#!Ke(B

e$B$h$m$7$/$*4j$$$7$^$9!#e(B