Add --enable-trace-log install option (ohler55#832)

I think the trace log feature is for debugging and most people don't use it. Therefore, I usually want to improve performance by removing unnecessary instructions. − | before | after | result -- | -- | -- | -- Oj.dump | 1.440M | 1.697M | 1.178x ### Environment - Linux - Manjaro Linux x86_64 - Kernel: 6.1.1-1-MANJARO - AMD Ryzen 7 5800H - gcc version 12.2.0 - Ruby 3.2.0 ### Before ``` Warming up -------------------------------------- Oj.dump 142.510k i/100ms Calculating ------------------------------------- Oj.dump 1.440M (± 0.4%) i/s - 14.536M in 10.091795s ``` ### After ``` Warming up -------------------------------------- Oj.dump 165.140k i/100ms Calculating ------------------------------------- Oj.dump 1.697M (± 0.7%) i/s - 17.009M in 10.025122s ``` ### Test code ```ruby require 'benchmark/ips' require 'oj' data = [[1,2,3,4,5]]*10 Benchmark.ips do |x| x.time = 10 x.report('Oj.dump') do Oj.dump(data) end end ```
admariner · Jan 9, 2023 · 8a1773d · 8a1773d
1 parent 7a5a499
commit 8a1773d
Show file tree

Hide file tree

Showing 14 changed files with 91 additions and 150 deletions.
diff --git a/README.md b/README.md
@@ -70,6 +70,7 @@ links.
  - [{file:Compatibility.md}](pages/Compatibility.md) lists current compatibility with Rubys and Rails.
  - [{file:Advanced.md}](pages/Advanced.md) for fast parser and marshalling features.
  - [{file:Security.md}](pages/Security.md) for security considerations.
+ - [{file:InstallOptions.md}](pages/InstallOptions.md) for install option.
 
 ## Releases
 

diff --git a/ext/oj/compat.c b/ext/oj/compat.c
@@ -54,9 +54,7 @@ static void hash_set_cstr(ParseInfo pi, Val kval, const char *str, size_t len, c
         } else {
             rb_hash_aset(parent->val, rkey, rstr);
         }
-        if (RB_UNLIKELY(Yes == pi->options.trace)) {
-            oj_trace_parse_call("set_string", pi, __FILE__, __LINE__, rstr);
-        }
+        TRACE_PARSE_CALL(pi->options.trace, "set_string", pi, rstr);
     }
 }
 
@@ -68,9 +66,7 @@ static VALUE start_hash(ParseInfo pi) {
     } else {
         h = rb_hash_new();
     }
-    if (RB_UNLIKELY(Yes == pi->options.trace)) {
-        oj_trace_parse_in("start_hash", pi, __FILE__, __LINE__);
-    }
+    TRACE_PARSE_IN(pi->options.trace, "start_hash", pi);
     return h;
 }
 
@@ -93,9 +89,7 @@ static void end_hash(struct _parseInfo *pi) {
             parent->classname = 0;
         }
     }
-    if (RB_UNLIKELY(Yes == pi->options.trace)) {
-        oj_trace_parse_hash_end(pi, __FILE__, __LINE__);
-    }
+    TRACE_PARSE_HASH_END(pi->options.trace, pi);
 }
 
 static void add_cstr(ParseInfo pi, const char *str, size_t len, const char *orig) {
@@ -110,16 +104,12 @@ static void add_cstr(ParseInfo pi, const char *str, size_t len, const char *orig
         }
     }
     pi->stack.head->val = rstr;
-    if (RB_UNLIKELY(Yes == pi->options.trace)) {
-        oj_trace_parse_call("add_string", pi, __FILE__, __LINE__, rstr);
-    }
+    TRACE_PARSE_CALL(pi->options.trace, "add_string", pi, rstr);
 }
 
 static void add_num(ParseInfo pi, NumInfo ni) {
     pi->stack.head->val = oj_num_as_value(ni);
-    if (RB_UNLIKELY(Yes == pi->options.trace)) {
-        oj_trace_parse_call("add_number", pi, __FILE__, __LINE__, pi->stack.head->val);
-    }
+    TRACE_PARSE_CALL(pi->options.trace, "add_number", pi, pi->stack.head->val);
 }
 
 static void hash_set_num(struct _parseInfo *pi, Val parent, NumInfo ni) {
@@ -138,9 +128,7 @@ static void hash_set_num(struct _parseInfo *pi, Val parent, NumInfo ni) {
     } else {
         rb_hash_aset(stack_peek(&pi->stack)->val, oj_calc_hash_key(pi, parent), rval);
     }
-    if (RB_UNLIKELY(Yes == pi->options.trace)) {
-        oj_trace_parse_call("set_number", pi, __FILE__, __LINE__, rval);
-    }
+    TRACE_PARSE_CALL(pi->options.trace, "set_number", pi, rval);
 }
 
 static void hash_set_value(ParseInfo pi, Val parent, VALUE value) {
@@ -157,18 +145,14 @@ static void hash_set_value(ParseInfo pi, Val parent, VALUE value) {
     } else {
         rb_hash_aset(stack_peek(&pi->stack)->val, oj_calc_hash_key(pi, parent), value);
     }
-    if (RB_UNLIKELY(Yes == pi->options.trace)) {
-        oj_trace_parse_call("set_value", pi, __FILE__, __LINE__, value);
-    }
+    TRACE_PARSE_CALL(pi->options.trace, "set_value", pi, value);
 }
 
 static VALUE start_array(ParseInfo pi) {
     if (Qnil != pi->options.array_class) {
         return rb_class_new_instance(0, NULL, pi->options.array_class);
     }
-    if (RB_UNLIKELY(Yes == pi->options.trace)) {
-        oj_trace_parse_in("start_array", pi, __FILE__, __LINE__);
-    }
+    TRACE_PARSE_IN(pi->options.trace, "start_array", pi);
     return rb_ary_new();
 }
 
@@ -184,9 +168,7 @@ static void array_append_num(ParseInfo pi, NumInfo ni) {
     } else {
         rb_ary_push(parent->val, rval);
     }
-    if (RB_UNLIKELY(Yes == pi->options.trace)) {
-        oj_trace_parse_call("append_number", pi, __FILE__, __LINE__, rval);
-    }
+    TRACE_PARSE_CALL(pi->options.trace, "append_number", pi, rval);
 }
 
 static void array_append_cstr(ParseInfo pi, const char *str, size_t len, const char *orig) {
@@ -201,9 +183,7 @@ static void array_append_cstr(ParseInfo pi, const char *str, size_t len, const c
         }
     }
     rb_ary_push(stack_peek(&pi->stack)->val, rstr);
-    if (RB_UNLIKELY(Yes == pi->options.trace)) {
-        oj_trace_parse_call("append_string", pi, __FILE__, __LINE__, rstr);
-    }
+    TRACE_PARSE_CALL(pi->options.trace, "append_string", pi, rstr);
 }
 
 void oj_set_compat_callbacks(ParseInfo pi) {

diff --git a/ext/oj/custom.c b/ext/oj/custom.c
@@ -479,17 +479,13 @@ static VALUE dump_common(VALUE obj, int depth, Out out) {
         const char    *s;
         int            len;
 
-        if (RB_UNLIKELY(Yes == out->opts->trace)) {
-            oj_trace("to_json", obj, __FILE__, __LINE__, depth + 1, TraceRubyIn);
-        }
+        TRACE(out->opts->trace, "to_json", obj, depth + 1, TraceRubyIn);
         if (0 == rb_obj_method_arity(obj, oj_to_json_id)) {
             rs = rb_funcall(obj, oj_to_json_id, 0);
         } else {
             rs = rb_funcall2(obj, oj_to_json_id, out->argc, out->argv);
         }
-        if (RB_UNLIKELY(Yes == out->opts->trace)) {
-            oj_trace("to_json", obj, __FILE__, __LINE__, depth + 1, TraceRubyOut);
-        }
+        TRACE(out->opts->trace, "to_json", obj, depth + 1, TraceRubyOut);
         s   = RSTRING_PTR(rs);
         len = (int)RSTRING_LEN(rs);
 
@@ -499,19 +495,15 @@ static VALUE dump_common(VALUE obj, int depth, Out out) {
     } else if (Yes == out->opts->as_json && rb_respond_to(obj, oj_as_json_id)) {
         volatile VALUE aj;
 
-        if (RB_UNLIKELY(Yes == out->opts->trace)) {
-            oj_trace("as_json", obj, __FILE__, __LINE__, depth + 1, TraceRubyIn);
-        }
+        TRACE(out->opts->trace, "as_json", obj, depth + 1, TraceRubyIn);
         // Some classes elect to not take an options argument so check the arity
         // of as_json.
         if (0 == rb_obj_method_arity(obj, oj_as_json_id)) {
             aj = rb_funcall(obj, oj_as_json_id, 0);
         } else {
             aj = rb_funcall2(obj, oj_as_json_id, out->argc, out->argv);
         }
-        if (RB_UNLIKELY(Yes == out->opts->trace)) {
-            oj_trace("as_json", obj, __FILE__, __LINE__, depth + 1, TraceRubyOut);
-        }
+        TRACE(out->opts->trace, "as_json", obj, depth + 1, TraceRubyOut);
         // Catch the obvious brain damaged recursive dumping.
         if (aj == obj) {
             volatile VALUE rstr = rb_funcall(obj, oj_to_s_id, 0);
@@ -876,9 +868,7 @@ static DumpFunc custom_funcs[] = {
 void oj_dump_custom_val(VALUE obj, int depth, Out out, bool as_ok) {
     int type = rb_type(obj);
 
-    if (RB_UNLIKELY(Yes == out->opts->trace)) {
-        oj_trace("dump", obj, __FILE__, __LINE__, depth, TraceIn);
-    }
+    TRACE(out->opts->trace, "dump", obj, depth, TraceIn);
     if (MAX_DEPTH < depth) {
         rb_raise(rb_eNoMemError, "Too deeply nested.\n");
     }
@@ -887,16 +877,12 @@ void oj_dump_custom_val(VALUE obj, int depth, Out out, bool as_ok) {
 
         if (NULL != f) {
             f(obj, depth, out, true);
-            if (RB_UNLIKELY(Yes == out->opts->trace)) {
-                oj_trace("dump", obj, __FILE__, __LINE__, depth, TraceOut);
-            }
+            TRACE(out->opts->trace, "dump", obj, depth, TraceOut);
             return;
         }
     }
     oj_dump_nil(Qnil, depth, out, false);
-    if (RB_UNLIKELY(Yes == out->opts->trace)) {
-        oj_trace("dump", Qnil, __FILE__, __LINE__, depth, TraceOut);
-    }
+    TRACE(out->opts->trace, "dump", Qnil, depth, TraceOut);
 }
 
 ///// load functions /////
@@ -969,9 +955,7 @@ static void end_hash(struct _parseInfo *pi) {
         }
         parent->clas = Qundef;
     }
-    if (RB_UNLIKELY(Yes == pi->options.trace)) {
-        oj_trace_parse_hash_end(pi, __FILE__, __LINE__);
-    }
+    TRACE_PARSE_HASH_END(pi->options.trace, pi);
 }
 
 static void hash_set_num(struct _parseInfo *pi, Val kval, NumInfo ni) {

diff --git a/ext/oj/dump.c b/ext/oj/dump.c
@@ -736,13 +736,9 @@ void oj_dump_raw_json(VALUE obj, int depth, Out out) {
     } else {
         volatile VALUE jv;
 
-        if (RB_UNLIKELY(Yes == out->opts->trace)) {
-            oj_trace("raw_json", obj, __FILE__, __LINE__, depth + 1, TraceRubyIn);
-        }
+        TRACE(out->opts->trace, "raw_json", obj, depth + 1, TraceRubyIn);
         jv = rb_funcall(obj, oj_raw_json_id, 2, RB_INT2NUM(depth), RB_INT2NUM(out->indent));
-        if (RB_UNLIKELY(Yes == out->opts->trace)) {
-            oj_trace("raw_json", obj, __FILE__, __LINE__, depth + 1, TraceRubyOut);
-        }
+        TRACE(out->opts->trace, "raw_json", obj, depth + 1, TraceRubyOut);
         oj_dump_raw(RSTRING_PTR(jv), (size_t)RSTRING_LEN(jv), out);
     }
 }

diff --git a/ext/oj/dump_compat.c b/ext/oj/dump_compat.c
@@ -109,17 +109,13 @@ dump_to_json(VALUE obj, Out out) {
     const char		*s;
     int			len;
 
-    if (RB_UNLIKELY(Yes == out->opts->trace)) {
-	oj_trace("to_json", obj, __FILE__, __LINE__, 0, TraceRubyIn);
-    }
+    TRACE(out->opts->trace, "to_json", obj, 0, TraceRubyIn);
     if (0 == rb_obj_method_arity(obj, oj_to_json_id)) {
 	rs = rb_funcall(obj, oj_to_json_id, 0);
     } else {
 	rs = rb_funcall2(obj, oj_to_json_id, out->argc, out->argv);
     }
-    if (RB_UNLIKELY(Yes == out->opts->trace)) {
-	oj_trace("to_json", obj, __FILE__, __LINE__, 0, TraceRubyOut);
-    }
+    TRACE(out->opts->trace, "to_json", obj, 0, TraceRubyOut);
 
     s = RSTRING_PTR(rs);
     len = (int)RSTRING_LEN(rs);
@@ -893,9 +889,7 @@ void
 oj_dump_compat_val(VALUE obj, int depth, Out out, bool as_ok) {
     int	type = rb_type(obj);
 
-    if (RB_UNLIKELY(Yes == out->opts->trace)) {
-	oj_trace("dump", obj, __FILE__, __LINE__, depth, TraceIn);
-    }
+    TRACE(out->opts->trace, "dump", obj, depth, TraceIn);
     if (out->opts->dump_opts.max_depth <= depth) {
 	// When JSON.dump is called then an ArgumentError is expected and the
 	// limit is the depth inclusive. If JSON.generate is called then a
@@ -918,14 +912,10 @@ oj_dump_compat_val(VALUE obj, int depth, Out out, bool as_ok) {
 
 	if (NULL != f) {
 	    f(obj, depth, out, as_ok);
-	    if (RB_UNLIKELY(Yes == out->opts->trace)) {
-		oj_trace("dump", obj, __FILE__, __LINE__, depth, TraceOut);
-	    }
+	    TRACE(out->opts->trace, "dump", obj, depth, TraceOut);
 	    return;
 	}
     }
     oj_dump_nil(Qnil, depth, out, false);
-    if (RB_UNLIKELY(Yes == out->opts->trace)) {
-	oj_trace("dump", Qnil, __FILE__, __LINE__, depth, TraceOut);
-    }
+    TRACE(out->opts->trace, "dump", Qnil, depth, TraceOut);
 }
diff --git a/ext/oj/dump_object.c b/ext/oj/dump_object.c
@@ -682,9 +682,7 @@ static DumpFunc obj_funcs[] = {
 void oj_dump_obj_val(VALUE obj, int depth, Out out) {
     int type = rb_type(obj);
 
-    if (RB_UNLIKELY(Yes == out->opts->trace)) {
-        oj_trace("dump", obj, __FILE__, __LINE__, depth, TraceIn);
-    }
+    TRACE(out->opts->trace, "dump", obj, depth, TraceIn);
     if (MAX_DEPTH < depth) {
         rb_raise(rb_eNoMemError, "Too deeply nested.\n");
     }
@@ -693,14 +691,10 @@ void oj_dump_obj_val(VALUE obj, int depth, Out out) {
 
         if (NULL != f) {
             f(obj, depth, out, false);
-            if (RB_UNLIKELY(Yes == out->opts->trace)) {
-                oj_trace("dump", obj, __FILE__, __LINE__, depth, TraceOut);
-            }
+            TRACE(out->opts->trace, "dump", obj, depth, TraceOut);
             return;
         }
     }
     oj_dump_nil(Qnil, depth, out, false);
-    if (RB_UNLIKELY(Yes == out->opts->trace)) {
-        oj_trace("dump", Qnil, __FILE__, __LINE__, depth, TraceOut);
-    }
+    TRACE(out->opts->trace, "dump", Qnil, depth, TraceOut);
 }
diff --git a/ext/oj/dump_strict.c b/ext/oj/dump_strict.c
@@ -338,9 +338,7 @@ static DumpFunc strict_funcs[] = {
 void oj_dump_strict_val(VALUE obj, int depth, Out out) {
     int type = rb_type(obj);
 
-    if (RB_UNLIKELY(Yes == out->opts->trace)) {
-        oj_trace("dump", obj, __FILE__, __LINE__, depth, TraceIn);
-    }
+    TRACE(out->opts->trace, "dump", obj, depth, TraceIn);
     if (MAX_DEPTH < depth) {
         rb_raise(rb_eNoMemError, "Too deeply nested.\n");
     }
@@ -349,9 +347,7 @@ void oj_dump_strict_val(VALUE obj, int depth, Out out) {
 
         if (NULL != f) {
             f(obj, depth, out, false);
-            if (RB_UNLIKELY(Yes == out->opts->trace)) {
-                oj_trace("dump", obj, __FILE__, __LINE__, depth, TraceOut);
-            }
+            TRACE(out->opts->trace, "dump", obj, depth, TraceOut);
             return;
         }
     }
@@ -386,9 +382,7 @@ static DumpFunc null_funcs[] = {
 void oj_dump_null_val(VALUE obj, int depth, Out out) {
     int type = rb_type(obj);
 
-    if (RB_UNLIKELY(Yes == out->opts->trace)) {
-        oj_trace("dump", obj, __FILE__, __LINE__, depth, TraceOut);
-    }
+    TRACE(out->opts->trace, "dump", obj, depth, TraceOut);
     if (MAX_DEPTH < depth) {
         rb_raise(rb_eNoMemError, "Too deeply nested.\n");
     }
@@ -397,14 +391,10 @@ void oj_dump_null_val(VALUE obj, int depth, Out out) {
 
         if (NULL != f) {
             f(obj, depth, out, false);
-            if (RB_UNLIKELY(Yes == out->opts->trace)) {
-                oj_trace("dump", obj, __FILE__, __LINE__, depth, TraceOut);
-            }
+            TRACE(out->opts->trace, "dump", obj, depth, TraceOut);
             return;
         }
     }
     oj_dump_nil(Qnil, depth, out, false);
-    if (RB_UNLIKELY(Yes == out->opts->trace)) {
-        oj_trace("dump", Qnil, __FILE__, __LINE__, depth, TraceOut);
-    }
+    TRACE(out->opts->trace, "dump", Qnil, depth, TraceOut);
 }
diff --git a/ext/oj/extconf.rb b/ext/oj/extconf.rb
@@ -39,6 +39,10 @@
   dflags['OJ_USE_SSE4_2'] = 1
 end
 
+if enable_config('trace-log', false)
+  dflags['OJ_ENABLE_TRACE_LOG'] = 1
+end
+
 dflags.each do |k,v|
   if v.nil?
     $CPPFLAGS += " -D#{k}"

diff --git a/ext/oj/object.c b/ext/oj/object.c
@@ -609,9 +609,7 @@ static void hash_set_value(ParseInfo pi, Val kval, VALUE value) {
 }
 
 static VALUE start_hash(ParseInfo pi) {
-    if (RB_UNLIKELY(Yes == pi->options.trace)) {
-        oj_trace_parse_in("start_hash", pi, __FILE__, __LINE__);
-    }
+    TRACE_PARSE_IN(pi->options.trace, "start_hash", pi);
     return Qnil;
 }
 
@@ -627,9 +625,7 @@ static void end_hash(ParseInfo pi) {
         oj_odd_free(oa);
         parent->odd_args = NULL;
     }
-    if (RB_UNLIKELY(Yes == pi->options.trace)) {
-        oj_trace_parse_hash_end(pi, __FILE__, __LINE__);
-    }
+    TRACE_PARSE_HASH_END(pi->options.trace, pi);
 }
 
 static void array_append_cstr(ParseInfo pi, const char *str, size_t len, const char *orig) {