ruby-changes:28825
From: ko1 <ko1@a...>
Date: Tue, 21 May 2013 17:19:19 +0900 (JST)
Subject: [ruby-changes:28825] ko1:r40877 (trunk): * gc.c: fix to collect additional information for GC::Profiler.
ko1 2013-05-21 17:19:07 +0900 (Tue, 21 May 2013) New Revision: 40877 http://svn.ruby-lang.org/cgi-bin/viewvc.cgi?view=rev&revision=40877 Log: * gc.c: fix to collect additional information for GC::Profiler. * major/minor GC * trigger reason of GC * gc.c (gc_profile_dump_on): change reporting format with added information. * gc.c (gc_profile_record_get): return added information by :GC_FLAGS => array. Modified files: trunk/ChangeLog trunk/gc.c Index: ChangeLog =================================================================== --- ChangeLog (revision 40876) +++ ChangeLog (revision 40877) @@ -1,3 +1,15 @@ https://github.com/ruby/ruby/blob/trunk/ChangeLog#L1 +Tue May 21 17:13:40 2013 Koichi Sasada <ko1@a...> + + * gc.c: fix to collect additional information for GC::Profiler. + * major/minor GC + * trigger reason of GC + + * gc.c (gc_profile_dump_on): change reporting format with + added information. + + * gc.c (gc_profile_record_get): return added information by + :GC_FLAGS => array. + Tue May 21 16:45:31 2013 Koichi Sasada <ko1@a...> * gc.c: GC::Profiler's sweeping time is accumulated all slot Index: gc.c =================================================================== --- gc.c (revision 40876) +++ gc.c (revision 40877) @@ -147,7 +147,22 @@ static ruby_gc_params_t initial_params = https://github.com/ruby/ruby/blob/trunk/gc.c#L147 #define GC_ENABLE_LAZY_SWEEP 1 #endif +typedef enum { + GPR_FLAG_NONE = 0x00, + GPR_FLAG_MINOR = 0x01, /* not major gc */ + GPR_FLAG_HAVE_FINALIZE = 0x02, + + /* reason */ + GPR_FLAG_NEWOBJ = 0x04, + GPR_FLAG_MALLOC = 0x08, + GPR_FLAG_METHOD = 0x10, + GPR_FLAG_CAPI = 0x20, + GPR_FLAG_STRESS = 0x30 +} gc_profile_record_flag; + typedef struct gc_profile_record { + int flags; + double gc_time; double gc_invoke_time; @@ -165,8 +180,6 @@ typedef struct gc_profile_record { https://github.com/ruby/ruby/blob/trunk/gc.c#L180 size_t heap_live_objects; size_t heap_free_objects; - int have_finalize; - size_t allocate_increase; size_t allocate_limit; #endif @@ -305,6 +318,7 @@ typedef struct rb_objspace { https://github.com/ruby/ruby/blob/trunk/gc.c#L318 gc_profile_record *record; size_t next_index; size_t size; + double invoke_time; #if USE_RGENGC @@ -438,14 +452,14 @@ static void aligned_free(void *); https://github.com/ruby/ruby/blob/trunk/gc.c#L452 static void init_mark_stack(mark_stack_t *stack); static VALUE lazy_sweep_enable(void); -static int garbage_collect(rb_objspace_t *); +static int garbage_collect(rb_objspace_t *, int reason); static int gc_prepare_free_objects(rb_objspace_t *); static void mark_tbl(rb_objspace_t *, st_table *); static void rest_sweep(rb_objspace_t *); static void gc_mark_stacked_objects(rb_objspace_t *); static double getrusage_time(void); -static inline void gc_prof_timer_start(rb_objspace_t *); +static inline void gc_prof_timer_start(rb_objspace_t *, int reason); static inline void gc_prof_timer_stop(rb_objspace_t *, int); static inline void gc_prof_mark_timer_start(rb_objspace_t *); static inline void gc_prof_mark_timer_stop(rb_objspace_t *); @@ -2305,11 +2319,10 @@ gc_prepare_free_objects(rb_objspace_t *o https://github.com/ruby/ruby/blob/trunk/gc.c#L2319 return TRUE; } else { - return garbage_collect(objspace); + return garbage_collect(objspace, GPR_FLAG_NEWOBJ); } } - if (!ready_to_gc(objspace)) return TRUE; during_gc++; @@ -2327,7 +2340,7 @@ gc_prepare_free_objects(rb_objspace_t *o https://github.com/ruby/ruby/blob/trunk/gc.c#L2340 } } - gc_prof_timer_start(objspace); + gc_prof_timer_start(objspace, GPR_FLAG_NEWOBJ | GPR_FLAG_MINOR); { gc_marks(objspace, TRUE); @@ -3678,7 +3691,7 @@ rb_gc_unregister_address(VALUE *addr) https://github.com/ruby/ruby/blob/trunk/gc.c#L3691 #define GC_NOTIFY 0 static int -garbage_collect(rb_objspace_t *objspace) +garbage_collect(rb_objspace_t *objspace, int reason) { if (GC_NOTIFY) printf("start garbage_collect()\n"); @@ -3691,7 +3704,7 @@ garbage_collect(rb_objspace_t *objspace) https://github.com/ruby/ruby/blob/trunk/gc.c#L3704 rest_sweep(objspace); - gc_prof_timer_start(objspace); + gc_prof_timer_start(objspace, reason); { during_gc++; gc_marks(objspace, FALSE); @@ -3703,22 +3716,31 @@ garbage_collect(rb_objspace_t *objspace) https://github.com/ruby/ruby/blob/trunk/gc.c#L3716 return TRUE; } +struct objspace_and_reason { + rb_objspace_t *objspace; + int reason; +}; + static void * gc_with_gvl(void *ptr) { - return (void *)(VALUE)garbage_collect((rb_objspace_t *)ptr); + struct objspace_and_reason *oar = (struct objspace_and_reason *)ptr; + return (void *)(VALUE)garbage_collect(oar->objspace, oar->reason); } static int -garbage_collect_with_gvl(rb_objspace_t *objspace) +garbage_collect_with_gvl(rb_objspace_t *objspace, int reason) { if (dont_gc) return TRUE; if (ruby_thread_has_gvl_p()) { - return garbage_collect(objspace); + return garbage_collect(objspace, reason); } else { if (ruby_native_thread_p()) { - return (int)(VALUE)rb_thread_call_with_gvl(gc_with_gvl, (void *)objspace); + struct objspace_and_reason oar; + oar.objspace = objspace; + oar.reason = reason; + return (int)(VALUE)rb_thread_call_with_gvl(gc_with_gvl, (void *)&oar); } else { /* no ruby thread */ @@ -3731,7 +3753,7 @@ garbage_collect_with_gvl(rb_objspace_t * https://github.com/ruby/ruby/blob/trunk/gc.c#L3753 int rb_garbage_collect(void) { - return garbage_collect(&rb_objspace); + return garbage_collect(&rb_objspace, GPR_FLAG_CAPI); } #undef Init_stack @@ -3763,7 +3785,7 @@ void https://github.com/ruby/ruby/blob/trunk/gc.c#L3785 rb_gc(void) { rb_objspace_t *objspace = &rb_objspace; - garbage_collect(objspace); + garbage_collect(objspace, GPR_FLAG_METHOD); if (!finalizing) finalize_deferred(objspace); free_unused_heaps(objspace); } @@ -4193,7 +4215,7 @@ vm_malloc_prepare(rb_objspace_t *objspac https://github.com/ruby/ruby/blob/trunk/gc.c#L4215 if ((ruby_gc_stress && !ruby_disable_gc_stress) || (malloc_increase+size) > malloc_limit) { - garbage_collect_with_gvl(objspace); + garbage_collect_with_gvl(objspace, GPR_FLAG_MALLOC); } return size; @@ -4216,7 +4238,7 @@ vm_malloc_fixup(rb_objspace_t *objspace, https://github.com/ruby/ruby/blob/trunk/gc.c#L4238 #define TRY_WITH_GC(alloc) do { \ if (!(alloc) && \ - (!garbage_collect_with_gvl(objspace) || \ + (!garbage_collect_with_gvl(objspace, GPR_FLAG_MALLOC) || \ !(alloc))) { \ ruby_memerror(); \ } \ @@ -4256,7 +4278,7 @@ vm_xrealloc(rb_objspace_t *objspace, voi https://github.com/ruby/ruby/blob/trunk/gc.c#L4278 return 0; } if (ruby_gc_stress && !ruby_disable_gc_stress) - garbage_collect_with_gvl(objspace); + garbage_collect_with_gvl(objspace, GPR_FLAG_MALLOC); #if CALC_EXACT_MALLOC_SIZE size += sizeof(size_t); @@ -4266,7 +4288,7 @@ vm_xrealloc(rb_objspace_t *objspace, voi https://github.com/ruby/ruby/blob/trunk/gc.c#L4288 mem = realloc(ptr, size); if (!mem) { - if (garbage_collect_with_gvl(objspace)) { + if (garbage_collect_with_gvl(objspace, GPR_FLAG_MALLOC)) { mem = realloc(ptr, size); } if (!mem) { @@ -4638,12 +4660,13 @@ gc_prof_record(rb_objspace_t *objspace) https://github.com/ruby/ruby/blob/trunk/gc.c#L4660 } static inline void -gc_prof_timer_start(rb_objspace_t *objspace) +gc_prof_timer_start(rb_objspace_t *objspace, int reason) { if (objspace->profile.run) { size_t index = objspace->profile.next_index; gc_profile_record *record; + /* create new record */ objspace->profile.next_index++; if (!objspace->profile.record) { @@ -4662,6 +4685,7 @@ gc_prof_timer_start(rb_objspace_t *objsp https://github.com/ruby/ruby/blob/trunk/gc.c#L4685 record->gc_time = getrusage_time(); record->gc_invoke_time = record->gc_time - objspace->profile.invoke_time; + record->flags = reason | ((ruby_gc_stress && !ruby_disable_gc_stress) ? GPR_FLAG_STRESS : 0); } } @@ -4674,6 +4698,7 @@ gc_prof_timer_stop(rb_objspace_t *objspa https://github.com/ruby/ruby/blob/trunk/gc.c#L4698 gc_time = getrusage_time() - record->gc_time; if (gc_time < 0) gc_time = 0; + record->gc_time = gc_time; record->is_marked = !!(marked); gc_prof_set_heap_info(objspace, record); @@ -4783,6 +4808,8 @@ gc_prof_sweep_slot_timer_stop(rb_objspac https://github.com/ruby/ruby/blob/trunk/gc.c#L4808 sweep_time = getrusage_time() - objspace->profile.gc_sweep_start_time; if (sweep_time < 0) sweep_time = 0; record->gc_sweep_time += sweep_time; + + if (deferred_final_list) record->flags |= GPR_FLAG_HAVE_FINALIZE; } } @@ -4806,7 +4833,6 @@ gc_prof_set_heap_info(rb_objspace_t *obj https://github.com/ruby/ruby/blob/trunk/gc.c#L4833 record->heap_live_objects = live; record->heap_free_objects = total - live; record->heap_total_objects = total; - record->have_finalize = deferred_final_list ? Qtrue : Qfalse; record->heap_use_size = live * sizeof(RVALUE); record->heap_total_size = total * sizeof(RVALUE); } @@ -4839,6 +4865,19 @@ gc_profile_clear(void) https://github.com/ruby/ruby/blob/trunk/gc.c#L4865 return Qnil; } +static VALUE +gc_profile_flags(int flags) +{ + VALUE result = rb_ary_new(); + rb_ary_push(result, ID2SYM(rb_intern(flags & GPR_FLAG_MINOR ? "minor_gc" : "major_gc"))); + if (flags & GPR_FLAG_HAVE_FINALIZE) rb_ary_push(result, ID2SYM(rb_intern("HAVE_FINALIZE"))); + if (flags & GPR_FLAG_NEWOBJ) rb_ary_push(result, ID2SYM(rb_intern("CAUSED_BY_NEWOBJ"))); + if (flags & GPR_FLAG_MALLOC) rb_ary_push(result, ID2SYM(rb_intern("CAUSED_BY_MALLOC"))); + if (flags & GPR_FLAG_METHOD) rb_ary_push(result, ID2SYM(rb_intern("CAUSED_BY_METHOD"))); + if (flags & GPR_FLAG_STRESS) rb_ary_push(result, ID2SYM(rb_intern("CAUSED_BY_STRESS"))); + return result; +} + /* * call-seq: * GC::Profiler.raw_data -> [Hash, ...] @@ -4903,6 +4942,7 @@ gc_profile_record_get(void) https://github.com/ruby/ruby/blob/trunk/gc.c#L4942 for (i =0; i < objspace->profile.next_index; i++) { prof = rb_hash_new(); + rb_hash_aset(prof, ID2SYM(rb_intern("GC_FLAGS")), gc_profile_flags(objspace->profile.record[i].flags)); rb_hash_aset(prof, ID2SYM(rb_intern("GC_TIME")), DBL2NUM(objspace->profile.record[i].gc_time)); rb_hash_aset(prof, ID2SYM(rb_intern("GC_INVOKE_TIME")), DBL2NUM(objspace->profile.record[i].gc_invoke_time)); rb_hash_aset(prof, ID2SYM(rb_intern("HEAP_USE_SIZE")), SIZET2NUM(objspace->profile.record[i].heap_use_size)); @@ -4917,7 +4957,7 @@ gc_profile_record_get(void) https://github.com/ruby/ruby/blob/trunk/gc.c#L4957 rb_hash_aset(prof, ID2SYM(rb_intern("HEAP_USE_SLOTS")), SIZET2NUM(objspace->profile.record[i].heap_use_slots)); rb_hash_aset(prof, ID2SYM(rb_intern("HEAP_LIVE_OBJECTS")), SIZET2NUM(objspace->profile.record[i].heap_live_objects)); rb_hash_aset(prof, ID2SYM(rb_intern("HEAP_FREE_OBJECTS")), SIZET2NUM(objspace->profile.record[i].heap_free_objects)); - rb_hash_aset(prof, ID2SYM(rb_intern("HAVE_FINALIZE")), objspace->profile.record[i].have_finalize); + rb_hash_aset(prof, ID2SYM(rb_intern("HAVE_FINALIZE")), (objspace->profile.record[i].flags & GPR_FLAG_HAVE_FINALIZE) ? Qtrue : Qfalse); #endif rb_ary_push(gc_profile, prof); } @@ -4940,26 +4980,28 @@ gc_profile_dump_on(VALUE out, VALUE (*ap https://github.com/ruby/ruby/blob/trunk/gc.c#L4980 for (i = 0; i < count; i++) { record = &objspace->profile.record[i]; -#if !GC_PROFILE_MORE_DETAIL - if (record->is_marked) { -#endif - append(out, rb_sprintf("%5d %19.3f %20"PRIuSIZE" %20"PRIuSIZE" %20"PRIuSIZE" %30.20f\n", - index++, record->gc_invoke_time, record->heap_use_size, - record->heap_total_size, record->heap_total_objects, record->gc_time*1000)); -#if !GC_PROFILE_MORE_DETAIL - } -#endif + append(out, rb_sprintf("%5d %19.3f %20"PRIuSIZE" %20"PRIuSIZE" %20"PRIuSIZE" %30.20f\n", + index++, record->gc_invoke_time, record->heap_use_size, + record->heap_total_size, record->heap_total_objects, record->gc_time*1000)); } #if GC_PROFILE_MORE_DETAIL append(out, rb_str_new_cstr("\n\n" \ "More detail.\n" \ - "Index Allocate Increase Allocate Limit Use Slot Have Finalize Mark Time(ms) Sweep Time(ms)\n")); + "Index Flags Allocate Increase Allocate Limit Use Slot Mark Time(ms) Sweep Time(ms)\n")); index = 1; for (i = 0; i < count; i++) { record = &objspace->profile.record[i]; - append(out, rb_sprintf("%5d %17"PRIuSIZE" %17"PRIuSIZE" %9"PRIuSIZE" %14s %25.20f %25.20f\n", - index++, record->allocate_increase, record->allocate_limit, - record->heap_use_slots, (record->have_finalize ? "true" : "false"), + append(out, rb_sprintf("%5d %c/%c/%s%c %17"PRIuSIZE" %17"PRIuSIZE" %9"PRIuSIZE" %25.20f %25.20f\n", + index++, + (record->flags & GPR_FLAG_MINOR) ? '-' : '+', + (record->flags & GPR_FLAG_HAVE_FINALIZE) ? 'F' : '.', + (record->flags & GPR_FLAG_NEWOBJ) ? "NEWOBJ" : + (record->flags & GPR_FLAG_MALLOC) ? "MALLOC" : + (record->flags & GPR_FLAG_METHOD) ? "METHOD" : + (record->flags & GPR_FLAG_CAPI) ? "CAPI__" : "?????", + (record->flags & GPR_FLAG_STRESS) ? '!' : ' ', + record->allocate_increase, record->allocate_limit, + record->heap_use_slots, record->gc_mark_time*1000, record->gc_sweep_time*1000)); } #endif -- ML: ruby-changes@q... Info: http://www.atdot.net/~ko1/quickml/