RUBY_DEBUG_LOG_TIME to print times

`RUBY_DEBUG_LOG=1 RUBY_DEBUG_LOG_TIME=1 ruby ...` will prints
debug logs with current time.

common.mk

@@ -3810,6 +3810,7 @@ debug.$(OBJEXT): {$(VPATH)}defines.h
 debug.$(OBJEXT): {$(VPATH)}encindex.h
 debug.$(OBJEXT): {$(VPATH)}encoding.h
 debug.$(OBJEXT): {$(VPATH)}eval_intern.h
+debug.$(OBJEXT): {$(VPATH)}hrtime.h
 debug.$(OBJEXT): {$(VPATH)}id.h
 debug.$(OBJEXT): {$(VPATH)}id_table.h
 debug.$(OBJEXT): {$(VPATH)}intern.h

debug.c

@@ -27,6 +27,7 @@
 #include "vm_callinfo.h"
 #include "ruby/thread_native.h"
 #include "ractor_core.h"
+#include "hrtime.h"
 
 /* This is the only place struct RIMemo is actually used */
 struct RIMemo {
@@ -291,7 +292,9 @@ static struct {
     struct debug_log_filter filters[MAX_DEBUG_LOG_FILTER_NUM];
     unsigned int filters_num;
     bool show_pid;
+    bool show_time;
     rb_nativethread_lock_t lock;
+    rb_hrtime_t prev_time;
     FILE *output;
 } debug_log;
 
@@ -411,6 +414,10 @@ setup_debug_log(void)
         if (getenv("RUBY_DEBUG_LOG_PID")) {
             debug_log.show_pid = true;
         }
+        if (getenv("RUBY_DEBUG_LOG_TIME")) {
+            debug_log.show_time = true;
+            debug_log.prev_time = rb_hrtime_now();
+        }
     }
 }
 
@@ -512,6 +519,16 @@ ruby_debug_log(const char *file, int line, const char *func_name, const char *fm
         len += r;
     }
 
+    if (debug_log.show_time) {
+        rb_hrtime_t now = rb_hrtime_now();
+        rb_hrtime_t diff = now > debug_log.prev_time ? now - debug_log.prev_time : 0;
+        debug_log.prev_time = now;
+
+        r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN, "%lu\t", (unsigned long)(diff / 1000L));
+        if (r < 0) rb_bug("ruby_debug_log returns %d\n", r);
+        len += r;
+    }
+
     // message title
     if (func_name && len < MAX_DEBUG_LOG_MESSAGE_LEN) {
         r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN, "%s\t", func_name);