refactoring debug_counter.

* debug_counter.h: add comments for each counters.

* debug_counter.h: add some counters (see added comments for details).
  * obj_newobj
  * obj_newobj_slowpath
  * obj_newobj_wb_unprotected
  * obj_hash_empty
  * obj_hash_under4
  * obj_hash_ge4
  * obj_hash_ge8
  * heap_xmalloc
  * heap_xrealloc
  * heap_xfree

* gc.c: add some debug counters (see the above list).

* debug_counter.c (rb_debug_counter_show_results): accept
  a header message.

* signal.c (ruby_default_signal): show debug counter results
  and malloc info (rb_malloc_info_show_results()) before
  SIGNAL exit.


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

debug_counter.c

@@ -9,9 +9,9 @@
 **********************************************************************/
 
 #include "debug_counter.h"
-#include <stdio.h>
-
 #if USE_DEBUG_COUNTER
+#include <stdio.h>
+#include <locale.h>
 #include "internal.h"
 
 static const char *const debug_counter_names[] = {
@@ -23,19 +23,33 @@ static const char *const debug_counter_names[] = {
 
 size_t rb_debug_counter[numberof(debug_counter_names)];
 
-__attribute__((destructor))
+void
-static void
+rb_debug_counter_show_results(const char *msg)
-rb_debug_counter_show_results(void)
 {
     const char *env = getenv("RUBY_DEBUG_COUNTER_DISABLE");
+
+    setlocale(LC_NUMERIC, "");
+
     if (env == NULL || strcmp("1", env) != 0) {
 	int i;
+        fprintf(stderr, "[RUBY_DEBUG_COUNTER]\t%d %s\n", getpid(), msg);
 	for (i=0; i<RB_DEBUG_COUNTER_MAX; i++) {
-	    fprintf(stderr, "[RUBY_DEBUG_COUNTER]\t%s\t%"PRIuSIZE"\n",
+	    fprintf(stderr, "[RUBY_DEBUG_COUNTER]\t%-30s\t%'12"PRIuSIZE"\n",
 		    debug_counter_names[i],
 		    rb_debug_counter[i]);
 	}
     }
 }
 
+__attribute__((destructor))
+static void
+debug_counter_show_results_at_exit(void)
+{
+    rb_debug_counter_show_results("normal exit.");
+}
+#else
+void
+rb_debug_counter_show_results(const char *msg)
+{
+}
 #endif /* USE_DEBUG_COUNTER */

debug_counter.h

@@ -14,7 +14,19 @@
 
 #ifdef RB_DEBUG_COUNTER
 
-/* method search */
+/*
+ * method cache (mc) counts.
+ *
+ * * mc_inline_hit/miss: inline mc hit/miss counts (VM send insn)
+ * * mc_global_hit/miss: global method cache hit/miss counts
+ *                       two types: (1) inline cache miss (VM send insn)
+ *                                  (2) called from C (rb_funcall).
+ * * mc_global_state_miss: inline mc miss by global_state miss.
+ * * mc_class_serial_miss:            ... by mc_class_serial_miss
+ * * mc_cme_complement: cme complement counts.
+ * * mc_cme_complement_hit: cme cache hit counts.
+ * * mc_search_super: search_method() call counts.
+ */
 RB_DEBUG_COUNTER(mc_inline_hit)
 RB_DEBUG_COUNTER(mc_inline_miss)
 RB_DEBUG_COUNTER(mc_global_hit)
@@ -25,7 +37,17 @@ RB_DEBUG_COUNTER(mc_cme_complement)
 RB_DEBUG_COUNTER(mc_cme_complement_hit)
 RB_DEBUG_COUNTER(mc_search_super)
 
-/* ivar access */
+/* instance variable counts
+ *
+ * * ivar_get_ic_hit/miss: ivar_get inline cache (ic) hit/miss counts (VM insn)
+ * * ivar_get_ic_miss_serial: ivar_get ic miss reason by serial (VM insn)
+ * * ivar_get_ic_miss_unset:                      ... by unset (VM insn)
+ * * ivar_get_ic_miss_noobject:                   ... by "not T_OBJECT" (VM insn)
+ * * ivar_set_...: same counts with ivar_set (VM insn)
+ * * ivar_get/set_base: call counts of "rb_ivar_get/set()".
+ *                      because of (1) ic miss.
+ *                                 (2) direct call by C extensions.
+ */
 RB_DEBUG_COUNTER(ivar_get_ic_hit)
 RB_DEBUG_COUNTER(ivar_get_ic_miss)
 RB_DEBUG_COUNTER(ivar_get_ic_miss_serial)
@@ -40,16 +62,53 @@ RB_DEBUG_COUNTER(ivar_set_ic_miss_noobject)
 RB_DEBUG_COUNTER(ivar_get_base)
 RB_DEBUG_COUNTER(ivar_set_base)
 
-/* lvar access */
+/* local variable counts
+ *
+ * * lvar_get: total lvar get counts (VM insn)
+ * * lvar_get_dynamic: lvar get counts if accessing upper env (VM insn)
+ * * lvar_set*: same as "get"
+ * * lvar_set_slowpath: counts using vm_env_write_slowpath()
+ */
 RB_DEBUG_COUNTER(lvar_get)
 RB_DEBUG_COUNTER(lvar_get_dynamic)
 RB_DEBUG_COUNTER(lvar_set)
 RB_DEBUG_COUNTER(lvar_set_dynamic)
 RB_DEBUG_COUNTER(lvar_set_slowpath)
 
-/* object counts */
+/* object allocation counts:
+ *
+ * * obj_newobj: newobj counts
+ * * obj_newobj_slowpath: newobj with slowpath counts
+ * * obj_newobj_wb_unprotected: newobj for wb_unprotecte.
+ * * obj_free: obj_free() counts
+ *
+ * * obj_[type]_[attr]: free'ed counts for each type.
+ * * [type]
+ *   * _obj: T_OBJECT
+ *   * _str: T_STRING
+ *   * _ary: T_ARRAY
+ *   * _hash: T_HASH
+ *
+ * * [attr]
+ *   * _ptr: R?? is not embed.
+ *   * _embed: R?? is embed.
+ * * type specific attr.
+ *   * str_shared: str is shared.
+ *   * str_nofree:        nofree
+ *   * str_fstr:          fstr
+ *   * hash_empty: hash is empty
+ *   * hash_under4:     has under 4 entries
+ *   * hash_ge4:        has n entries (4<=n<8)
+ *   * hash_ge8:        has n entries (8<=n)
+ */
+RB_DEBUG_COUNTER(obj_newobj)
+RB_DEBUG_COUNTER(obj_newobj_slowpath)
+RB_DEBUG_COUNTER(obj_newobj_wb_unprotected)
 RB_DEBUG_COUNTER(obj_free)
 
+RB_DEBUG_COUNTER(obj_obj_ptr)
+RB_DEBUG_COUNTER(obj_obj_embed)
+
 RB_DEBUG_COUNTER(obj_str_ptr)
 RB_DEBUG_COUNTER(obj_str_embed)
 RB_DEBUG_COUNTER(obj_str_shared)
@@ -59,13 +118,24 @@ RB_DEBUG_COUNTER(obj_str_fstr)
 RB_DEBUG_COUNTER(obj_ary_ptr)
 RB_DEBUG_COUNTER(obj_ary_embed)
 
-RB_DEBUG_COUNTER(obj_obj_ptr)
+RB_DEBUG_COUNTER(obj_hash_empty)
-RB_DEBUG_COUNTER(obj_obj_embed)
+RB_DEBUG_COUNTER(obj_hash_under4)
+RB_DEBUG_COUNTER(obj_hash_ge4)
+RB_DEBUG_COUNTER(obj_hash_ge8)
 
-/* load */
+/* heap function counts
+ *
+ * * heap_xmalloc/realloc/xfree: call counts
+ */
+RB_DEBUG_COUNTER(heap_xmalloc)
+RB_DEBUG_COUNTER(heap_xrealloc)
+RB_DEBUG_COUNTER(heap_xfree)
+
+/* load (not implemented yet) */
+/*
 RB_DEBUG_COUNTER(load_files)
 RB_DEBUG_COUNTER(load_path_is_not_realpath)
-
+*/
 #endif
 
 #ifndef RUBY_DEBUG_COUNTER_H
@@ -106,4 +176,6 @@ rb_debug_counter_add(enum rb_debug_counter_type type, int add, int cond)
 #define RB_DEBUG_COUNTER_INC_IF(type, cond)     (cond)
 #endif
 
+void rb_debug_counter_show_results(const char *msg);
+
 #endif /* RUBY_DEBUG_COUNTER_H */

gc.c

@@ -1948,6 +1948,9 @@ newobj_of(VALUE klass, VALUE flags, VALUE v1, VALUE v2, VALUE v3, int wb_protect
     rb_objspace_t *objspace = &rb_objspace;
     VALUE obj;
 
+    RB_DEBUG_COUNTER_INC(obj_newobj);
+    (void)RB_DEBUG_COUNTER_INC_IF(obj_newobj_wb_unprotected, !wb_protected);
+
 #if GC_DEBUG_STRESS_TO_CLASS
     if (UNLIKELY(stress_to_class)) {
 	long i, cnt = RARRAY_LEN(stress_to_class);
@@ -1964,6 +1967,8 @@ newobj_of(VALUE klass, VALUE flags, VALUE v1, VALUE v2, VALUE v3, int wb_protect
 	return newobj_init(klass, flags, v1, v2, v3, wb_protected, objspace, obj);
     }
     else {
+        RB_DEBUG_COUNTER_INC(obj_newobj_slowpath);
+
 	return wb_protected ?
 	  newobj_slowpath_wb_protected(klass, flags, v1, v2, v3, objspace) :
 	  newobj_slowpath_wb_unprotected(klass, flags, v1, v2, v3, objspace);
@@ -2256,7 +2261,20 @@ obj_free(rb_objspace_t *objspace, VALUE obj)
       case T_HASH:
 	if (RANY(obj)->as.hash.ntbl) {
 	    st_free_table(RANY(obj)->as.hash.ntbl);
+
+            if (RHASH_SIZE(obj) >= 8) {
+                RB_DEBUG_COUNTER_INC(obj_hash_ge8);
+            }
+            if (RHASH_SIZE(obj) >= 4) {
+                RB_DEBUG_COUNTER_INC(obj_hash_ge4);
+            }
+            else {
+                RB_DEBUG_COUNTER_INC(obj_hash_under4);
+            }
 	}
+        else {
+            RB_DEBUG_COUNTER_INC(obj_hash_empty);
+        }
 	break;
       case T_REGEXP:
 	if (RANY(obj)->as.regexp.ptr) {
@@ -7959,6 +7977,7 @@ objspace_xmalloc0(rb_objspace_t *objspace, size_t size)
 
     size = objspace_malloc_prepare(objspace, size);
     TRY_WITH_GC(mem = malloc(size));
+    RB_DEBUG_COUNTER_INC(heap_xmalloc);
     return objspace_malloc_fixup(objspace, mem, size);
 }
 
@@ -8012,11 +8031,11 @@ objspace_xrealloc(rb_objspace_t *objspace, void *ptr, size_t new_size, size_t ol
 
     objspace_malloc_increase(objspace, mem, new_size, old_size, MEMOP_TYPE_REALLOC);
 
+    RB_DEBUG_COUNTER_INC(heap_xrealloc);
     return mem;
 }
 
-#if CALC_EXACT_MALLOC_SIZE
+#if CALC_EXACT_MALLOC_SIZE && USE_GC_MALLOC_OBJ_INFO_DETAILS
-#if USE_GC_MALLOC_OBJ_INFO_DETAILS
 
 #define MALLOC_INFO_GEN_SIZE 100
 #define MALLOC_INFO_SIZE_SIZE 10
@@ -8037,8 +8056,8 @@ mmalloc_info_file_i(st_data_t key, st_data_t val, st_data_t dmy)
 }
 
 __attribute__((destructor))
-static void
+void
-malloc_info_show_results(void)
+rb_malloc_info_show_results(void)
 {
     int i;
 
@@ -8064,7 +8083,11 @@ malloc_info_show_results(void)
         st_foreach(malloc_info_file_table, mmalloc_info_file_i, 0);
     }
 }
-#endif
+#else
+void
+rb_malloc_info_show_results(void)
+{
+}
 #endif
 
 static void
@@ -8129,6 +8152,7 @@ objspace_xfree(rb_objspace_t *objspace, void *ptr, size_t old_size)
     old_size = objspace_malloc_size(objspace, ptr, old_size);
 
     free(ptr);
+    RB_DEBUG_COUNTER_INC(heap_xfree);
 
     objspace_malloc_increase(objspace, ptr, 0, old_size, MEMOP_TYPE_FREE);
 }

signal.c

@@ -395,9 +395,17 @@ interrupt_init(int argc, VALUE *argv, VALUE self)
     return rb_call_super(2, args);
 }
 
+#include "debug_counter.h"
+void rb_malloc_info_show_results(void); /* gc.c */
+
 void
 ruby_default_signal(int sig)
 {
+#if USE_DEBUG_COUNTER
+    rb_debug_counter_show_results("killed by signal.");
+#endif
+    rb_malloc_info_show_results();
+
     signal(sig, SIG_DFL);
     raise(sig);
 }