debug.c

   1 /**********************************************************************
   2
   3   debug.c -
   4
   5   $Author$
   6   created at: 04/08/25 02:31:54 JST
   7
   8   Copyright (C) 2004-2007 Koichi Sasada
   9
  10 **********************************************************************/
  11
  12 #include "ruby/internal/config.h"
  13
  14 #include <stdio.h>
  15
  16 #include "eval_intern.h"
  17 #include "encindex.h"
  18 #include "id.h"
  19 #include "internal/signal.h"
  20 #include "ruby/encoding.h"
  21 #include "ruby/io.h"
  22 #include "ruby/ruby.h"
  23 #include "ruby/util.h"
  24 #include "symbol.h"
  25 #include "vm_core.h"
  26 #include "vm_debug.h"
  27 #include "vm_callinfo.h"
  28 #include "ruby/thread_native.h"
  29 #include "ractor_core.h"
  30
  31 /* This is the only place struct RIMemo is actually used */
  32 struct RIMemo {
  33     VALUE flags;
  34     VALUE v0;
  35     VALUE v1;
  36     VALUE v2;
  37     VALUE v3;
  38 };
  39
  40 /* for gdb */
  41 const union {
  42     enum ruby_special_consts    special_consts;
  43     enum ruby_value_type        value_type;
  44     enum ruby_tag_type          tag_type;
  45     enum node_type              node_type;
  46     enum ruby_method_ids        method_ids;
  47     enum ruby_id_types          id_types;
  48     enum ruby_fl_type           fl_types;
  49     enum ruby_fl_ushift         fl_ushift;
  50     enum ruby_encoding_consts   encoding_consts;
  51     enum ruby_coderange_type    enc_coderange_types;
  52     enum ruby_econv_flag_type   econv_flag_types;
  53     rb_econv_result_t           econv_result;
  54     enum ruby_preserved_encindex encoding_index;
  55     enum ruby_robject_flags     robject_flags;
  56     enum ruby_rmodule_flags     rmodule_flags;
  57     enum ruby_rstring_flags     rstring_flags;
  58     enum ruby_rarray_flags      rarray_flags;
  59     enum ruby_rarray_consts     rarray_consts;
  60     enum {
  61         RUBY_FMODE_READABLE             = FMODE_READABLE,
  62         RUBY_FMODE_WRITABLE             = FMODE_WRITABLE,
  63         RUBY_FMODE_READWRITE            = FMODE_READWRITE,
  64         RUBY_FMODE_BINMODE              = FMODE_BINMODE,
  65         RUBY_FMODE_SYNC                 = FMODE_SYNC,
  66         RUBY_FMODE_TTY                  = FMODE_TTY,
  67         RUBY_FMODE_DUPLEX               = FMODE_DUPLEX,
  68         RUBY_FMODE_APPEND               = FMODE_APPEND,
  69         RUBY_FMODE_CREATE               = FMODE_CREATE,
  70         RUBY_FMODE_NOREVLOOKUP          = 0x00000100,
  71         RUBY_FMODE_TRUNC                = FMODE_TRUNC,
  72         RUBY_FMODE_TEXTMODE             = FMODE_TEXTMODE,
  73         RUBY_FMODE_EXTERNAL             = 0x00010000,
  74         RUBY_FMODE_SETENC_BY_BOM        = FMODE_SETENC_BY_BOM,
  75         RUBY_FMODE_UNIX                 = 0x00200000,
  76         RUBY_FMODE_INET                 = 0x00400000,
  77         RUBY_FMODE_INET6                = 0x00800000,
  78
  79         RUBY_NODE_TYPESHIFT = NODE_TYPESHIFT,
  80         RUBY_NODE_TYPEMASK  = NODE_TYPEMASK,
  81         RUBY_NODE_LSHIFT    = NODE_LSHIFT,
  82         RUBY_NODE_FL_NEWLINE   = NODE_FL_NEWLINE
  83     } various;
  84     union {
  85         enum imemo_type                     types;
  86         enum {RUBY_IMEMO_MASK = IMEMO_MASK} mask;
  87         struct RIMemo                      *ptr;
  88     } imemo;
  89     struct RSymbol *symbol_ptr;
  90     enum vm_call_flag_bits vm_call_flags;
  91 } ruby_dummy_gdb_enums;
  92
  93 const SIGNED_VALUE RUBY_NODE_LMASK = NODE_LMASK;
  94
  95 int
  96 ruby_debug_print_indent(int level, int debug_level, int indent_level)
  97 {
  98     if (level < debug_level) {
  99         fprintf(stderr, "%*s", indent_level, "");
 100         fflush(stderr);
 101         return TRUE;
 102     }
 103     return FALSE;
 104 }
 105
 106 void
 107 ruby_debug_printf(const char *format, ...)
 108 {
 109     va_list ap;
 110     va_start(ap, format);
 111     vfprintf(stderr, format, ap);
 112     va_end(ap);
 113 }
 114
 115 #include "internal/gc.h"
 116
 117 VALUE
 118 ruby_debug_print_value(int level, int debug_level, const char *header, VALUE obj)
 119 {
 120     if (level < debug_level) {
 121         char buff[0x100];
 122         rb_raw_obj_info(buff, 0x100, obj);
 123
 124         fprintf(stderr, "DBG> %s: %s\n", header, buff);
 125         fflush(stderr);
 126     }
 127     return obj;
 128 }
 129
 130 void
 131 ruby_debug_print_v(VALUE v)
 132 {
 133     ruby_debug_print_value(0, 1, "", v);
 134 }
 135
 136 ID
 137 ruby_debug_print_id(int level, int debug_level, const char *header, ID id)
 138 {
 139     if (level < debug_level) {
 140         fprintf(stderr, "DBG> %s: %s\n", header, rb_id2name(id));
 141         fflush(stderr);
 142     }
 143     return id;
 144 }
 145
 146 NODE *
 147 ruby_debug_print_node(int level, int debug_level, const char *header, const NODE *node)
 148 {
 149     if (level < debug_level) {
 150         fprintf(stderr, "DBG> %s: %s (id: %d, line: %d, location: (%d,%d)-(%d,%d))\n",
 151                 header, ruby_node_name(nd_type(node)), nd_node_id(node), nd_line(node),
 152                 nd_first_lineno(node), nd_first_column(node),
 153                 nd_last_lineno(node), nd_last_column(node));
 154     }
 155     return (NODE *)node;
 156 }
 157
 158 void
 159 ruby_debug_print_n(const NODE *node)
 160 {
 161     ruby_debug_print_node(0, 1, "", node);
 162 }
 163
 164 void
 165 ruby_debug_breakpoint(void)
 166 {
 167     /* */
 168 }
 169
 170 #if defined _WIN32
 171 # if RUBY_MSVCRT_VERSION >= 80
 172 extern int ruby_w32_rtc_error;
 173 # endif
 174 #endif
 175 #if defined _WIN32 || defined __CYGWIN__
 176 #include <windows.h>
 177 UINT ruby_w32_codepage[2];
 178 #endif
 179 extern int ruby_rgengc_debug;
 180 extern int ruby_on_ci;
 181
 182 int
 183 ruby_env_debug_option(const char *str, int len, void *arg)
 184 {
 185     int ov;
 186     size_t retlen;
 187     unsigned long n;
 188 #define NAME_MATCH(name) (len == sizeof(name) - 1 && strncmp(str, (name), len) == 0)
 189 #define SET_WHEN(name, var, val) do {       \
 190         if (NAME_MATCH(name)) { \
 191             (var) = (val);                  \
 192             return 1;                       \
 193         }                                   \
 194     } while (0)
 195 #define NAME_MATCH_VALUE(name)                          \
 196     ((size_t)len >= sizeof(name)-1 &&                   \
 197      strncmp(str, (name), sizeof(name)-1) == 0 &&       \
 198      ((len == sizeof(name)-1 && !(len = 0)) ||          \
 199       (str[sizeof(name)-1] == '=' &&                    \
 200        (str += sizeof(name), len -= sizeof(name), 1))))
 201 #define SET_UINT(val) do { \
 202         n = ruby_scan_digits(str, len, 10, &retlen, &ov); \
 203         if (!ov && retlen) { \
 204             val = (unsigned int)n; \
 205         } \
 206         str += retlen; \
 207         len -= retlen; \
 208     } while (0)
 209 #define SET_UINT_LIST(name, vals, num) do { \
 210         int i; \
 211         for (i = 0; i < (num); ++i) { \
 212             SET_UINT((vals)[i]); \
 213             if (!len || *str != ':') break; \
 214             ++str; \
 215             --len; \
 216         } \
 217         if (len > 0) { \
 218             fprintf(stderr, "ignored "name" option: '%.*s'\n", len, str); \
 219         } \
 220     } while (0)
 221 #define SET_WHEN_UINT(name, vals, num, req) \
 222     if (NAME_MATCH_VALUE(name)) { \
 223         if (!len) req; \
 224         else SET_UINT_LIST(name, vals, num); \
 225         return 1; \
 226     }
 227
 228     if (NAME_MATCH("gc_stress")) {
 229         rb_gc_initial_stress_set(Qtrue);
 230         return 1;
 231     }
 232     SET_WHEN("core", ruby_enable_coredump, 1);
 233     SET_WHEN("ci", ruby_on_ci, 1);
 234     SET_WHEN_UINT("rgengc", &ruby_rgengc_debug, 1, ruby_rgengc_debug = 1);
 235 #if defined _WIN32
 236 # if RUBY_MSVCRT_VERSION >= 80
 237     SET_WHEN("rtc_error", ruby_w32_rtc_error, 1);
 238 # endif
 239 #endif
 240 #if defined _WIN32 || defined __CYGWIN__
 241     SET_WHEN_UINT("codepage", ruby_w32_codepage, numberof(ruby_w32_codepage),
 242                   fprintf(stderr, "missing codepage argument"));
 243 #endif
 244     return 0;
 245 }
 246
 247 static void
 248 set_debug_option(const char *str, int len, void *arg)
 249 {
 250     if (!ruby_env_debug_option(str, len, arg)) {
 251         fprintf(stderr, "unexpected debug option: %.*s\n", len, str);
 252     }
 253 }
 254
 255 #if USE_RUBY_DEBUG_LOG
 256 static void setup_debug_log(void);
 257 #else
 258 #define setup_debug_log()
 259 #endif
 260
 261 void
 262 ruby_set_debug_option(const char *str)
 263 {
 264     ruby_each_words(str, set_debug_option, 0);
 265     setup_debug_log();
 266 }
 267
 268 #if USE_RUBY_DEBUG_LOG
 269
 270 // RUBY_DEBUG_LOG features
 271 // See vm_debug.h comments for details.
 272
 273 #define MAX_DEBUG_LOG             0x1000
 274 #define MAX_DEBUG_LOG_MESSAGE_LEN 0x0200
 275 #define MAX_DEBUG_LOG_FILTER_LEN  0x0020
 276 #define MAX_DEBUG_LOG_FILTER_NUM  0x0010
 277
 278 enum ruby_debug_log_mode ruby_debug_log_mode;
 279
 280 struct debug_log_filter {
 281     enum debug_log_filter_type {
 282         dlf_all,
 283         dlf_file, // "file:..."
 284         dlf_func, // "func:..."
 285     } type;
 286     bool negative;
 287     char str[MAX_DEBUG_LOG_FILTER_LEN];
 288 };
 289
 290 static const char *dlf_type_names[] = {
 291     "all",
 292     "file",
 293     "func",
 294 };
 295
 296 #ifdef MAX_PATH
 297 #define DEBUG_LOG_MAX_PATH (MAX_PATH-1)
 298 #else
 299 #define DEBUG_LOG_MAX_PATH 255
 300 #endif
 301
 302 static struct {
 303     char *mem;
 304     unsigned int cnt;
 305     struct debug_log_filter filters[MAX_DEBUG_LOG_FILTER_NUM];
 306     unsigned int filters_num;
 307     bool show_pid;
 308     rb_nativethread_lock_t lock;
 309     char output_file[DEBUG_LOG_MAX_PATH+1];
 310     FILE *output;
 311 } debug_log;
 312
 313 static char *
 314 RUBY_DEBUG_LOG_MEM_ENTRY(unsigned int index)
 315 {
 316     return &debug_log.mem[MAX_DEBUG_LOG_MESSAGE_LEN * index];
 317 }
 318
 319 static enum debug_log_filter_type
 320 filter_type(const char *str, int *skiplen)
 321 {
 322     if (strncmp(str, "file:", 5) == 0) {
 323         *skiplen = 5;
 324         return dlf_file;
 325     }
 326     else if(strncmp(str, "func:", 5) == 0) {
 327         *skiplen = 5;
 328         return dlf_func;
 329     }
 330     else {
 331         *skiplen = 0;
 332         return dlf_all;
 333     }
 334 }
 335
 336 static void
 337 setup_debug_log_filter(void)
 338 {
 339     const char *filter_config = getenv("RUBY_DEBUG_LOG_FILTER");
 340
 341     if (filter_config && strlen(filter_config) > 0) {
 342         unsigned int i;
 343         for (i=0; i<MAX_DEBUG_LOG_FILTER_NUM && filter_config; i++) {
 344             size_t len;
 345             const char *str = filter_config;
 346             const char *p;
 347
 348             if ((p = strchr(str, ',')) == NULL) {
 349                 len = strlen(str);
 350                 filter_config = NULL;
 351             }
 352             else {
 353                 len = p - str - 1; // 1 is ','
 354                 filter_config = p + 1;
 355             }
 356
 357             // positive/negative
 358             if (*str == '-') {
 359                 debug_log.filters[i].negative = true;
 360                 str++;
 361             }
 362             else if (*str == '+') {
 363                 // negative is false on default.
 364                 str++;
 365             }
 366
 367             // type
 368             int skiplen;
 369             debug_log.filters[i].type = filter_type(str, &skiplen);
 370             len -= skiplen;
 371
 372             if (len >= MAX_DEBUG_LOG_FILTER_LEN) {
 373                 fprintf(stderr, "too long: %s (max:%d)\n", str, MAX_DEBUG_LOG_FILTER_LEN - 1);
 374                 exit(1);
 375             }
 376
 377             // body
 378             strncpy(debug_log.filters[i].str, str + skiplen, len);
 379             debug_log.filters[i].str[len] = 0;
 380         }
 381         debug_log.filters_num = i;
 382
 383         for (i=0; i<debug_log.filters_num; i++) {
 384             fprintf(stderr, "RUBY_DEBUG_LOG_FILTER[%d]=%s (%s%s)\n", i,
 385                     debug_log.filters[i].str,
 386                     debug_log.filters[i].negative ? "-" : "",
 387                     dlf_type_names[debug_log.filters[i].type]);
 388         }
 389     }
 390 }
 391
 392 static void
 393 setup_debug_log(void)
 394 {
 395     // check RUBY_DEBUG_LOG
 396     const char *log_config = getenv("RUBY_DEBUG_LOG");
 397     if (log_config && strlen(log_config) > 0) {
 398         if (strcmp(log_config, "mem") == 0) {
 399             debug_log.mem = (char *)malloc(MAX_DEBUG_LOG * MAX_DEBUG_LOG_MESSAGE_LEN);
 400             if (debug_log.mem == NULL) {
 401                 fprintf(stderr, "setup_debug_log failed (can't allocate memory)\n");
 402                 exit(1);
 403             }
 404             ruby_debug_log_mode |= ruby_debug_log_memory;
 405         }
 406         else if (strcmp(log_config, "stderr") == 0) {
 407             ruby_debug_log_mode |= ruby_debug_log_stderr;
 408         }
 409         else {
 410             ruby_debug_log_mode |= ruby_debug_log_file;
 411
 412             // pid extension with %p
 413             unsigned long len = strlen(log_config);
 414
 415             for (unsigned long i=0, j=0; i<len; i++) {
 416                 const char c = log_config[i];
 417
 418                 if (c == '%') {
 419                     i++;
 420                     switch (log_config[i]) {
 421                       case '%':
 422                         debug_log.output_file[j++] = '%';
 423                         break;
 424                       case 'p':
 425                         snprintf(debug_log.output_file + j, DEBUG_LOG_MAX_PATH - j, "%d", getpid());
 426                         j = strlen(debug_log.output_file);
 427                         break;
 428                       default:
 429                         fprintf(stderr, "can not parse RUBY_DEBUG_LOG filename: %s\n", log_config);
 430                         exit(1);
 431                     }
 432                 }
 433                 else {
 434                     debug_log.output_file[j++] = c;
 435                 }
 436
 437                 if (j >= DEBUG_LOG_MAX_PATH) {
 438                     fprintf(stderr, "RUBY_DEBUG_LOG=%s is too long\n", log_config);
 439                     exit(1);
 440                 }
 441             }
 442
 443             if ((debug_log.output = fopen(debug_log.output_file, "w")) == NULL) {
 444                 fprintf(stderr, "can not open %s for RUBY_DEBUG_LOG\n", log_config);
 445                 exit(1);
 446             }
 447             setvbuf(debug_log.output, NULL, _IONBF, 0);
 448         }
 449
 450         fprintf(stderr, "RUBY_DEBUG_LOG=%s %s%s%s\n", log_config,
 451                 (ruby_debug_log_mode & ruby_debug_log_memory) ? "[mem]" : "",
 452                 (ruby_debug_log_mode & ruby_debug_log_stderr) ? "[stderr]" : "",
 453                 (ruby_debug_log_mode & ruby_debug_log_file)   ? "[file]" : "");
 454         if (debug_log.output_file[0]) {
 455             fprintf(stderr, "RUBY_DEBUG_LOG filename=%s\n", debug_log.output_file);
 456         }
 457
 458         rb_nativethread_lock_initialize(&debug_log.lock);
 459
 460         setup_debug_log_filter();
 461
 462         if (getenv("RUBY_DEBUG_LOG_PID")) {
 463             debug_log.show_pid = true;
 464         }
 465     }
 466 }
 467
 468 static bool
 469 check_filter(const char *str, const struct debug_log_filter *filter, bool *state)
 470 {
 471     if (filter->negative) {
 472         if (strstr(str, filter->str) == NULL) {
 473             *state = true;
 474             return false;
 475         }
 476         else {
 477             *state = false;
 478             return true;
 479         }
 480     }
 481     else {
 482         if (strstr(str, filter->str) != NULL) {
 483             *state = true;
 484             return true;
 485         }
 486         else {
 487             *state = false;
 488             return false;
 489         }
 490     }
 491 }
 492
 493 //
 494 // RUBY_DEBUG_LOG_FILTER=-foo,-bar,baz,boo
 495 // returns true if
 496 //   (func_name or file_name) doesn't contain foo
 497 // and
 498 //   (func_name or file_name) doesn't contain bar
 499 // and
 500 //   (func_name or file_name) contains baz or boo
 501 //
 502 // RUBY_DEBUG_LOG_FILTER=foo,bar,-baz,-boo
 503 // returns true if
 504 //   (func_name or file_name) contains foo or bar
 505 // or
 506 //   (func_name or file_name) doesn't contain baz and
 507 //   (func_name or file_name) doesn't contain boo and
 508 //
 509 // You can specify "file:" (ex file:foo) or "func:" (ex  func:foo)
 510 // prefixes to specify the filter for.
 511 //
 512 bool
 513 ruby_debug_log_filter(const char *func_name, const char *file_name)
 514 {
 515     if (debug_log.filters_num > 0) {
 516         bool state = false;
 517
 518         for (unsigned int i = 0; i<debug_log.filters_num; i++) {
 519             const struct debug_log_filter *filter = &debug_log.filters[i];
 520
 521             switch (filter->type) {
 522               case dlf_all:
 523                 if (check_filter(func_name, filter, &state)) return state;
 524                 if (check_filter(file_name, filter, &state)) return state;
 525                 break;
 526               case dlf_func:
 527                 if (check_filter(func_name, filter, &state)) return state;
 528                 break;
 529               case dlf_file:
 530                 if (check_filter(file_name, filter, &state)) return state;
 531                 break;
 532             }
 533         }
 534         return state;
 535     }
 536     else {
 537         return true;
 538     }
 539 }
 540
 541 static const char *
 542 pretty_filename(const char *path)
 543 {
 544     // basename is one idea.
 545     const char *s;
 546     while ((s = strchr(path, '/')) != NULL) {
 547         path = s+1;
 548     }
 549     return path;
 550 }
 551
 552 #undef ruby_debug_log
 553 void
 554 ruby_debug_log(const char *file, int line, const char *func_name, const char *fmt, ...)
 555 {
 556     char buff[MAX_DEBUG_LOG_MESSAGE_LEN] = {0};
 557     int len = 0;
 558     int r = 0;
 559
 560     if (debug_log.show_pid) {
 561         r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN, "pid:%d\t", getpid());
 562         if (r < 0) rb_bug("ruby_debug_log returns %d", r);
 563         len += r;
 564     }
 565
 566     // message title
 567     if (func_name && len < MAX_DEBUG_LOG_MESSAGE_LEN) {
 568         r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN, "%s\t", func_name);
 569         if (r < 0) rb_bug("ruby_debug_log returns %d", r);
 570         len += r;
 571     }
 572
 573     // message
 574     if (fmt && len < MAX_DEBUG_LOG_MESSAGE_LEN) {
 575         va_list args;
 576         va_start(args, fmt);
 577         r = vsnprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, fmt, args);
 578         va_end(args);
 579         if (r < 0) rb_bug("ruby_debug_log vsnprintf() returns %d", r);
 580         len += r;
 581     }
 582
 583     // optional information
 584
 585     // C location
 586     if (file && len < MAX_DEBUG_LOG_MESSAGE_LEN) {
 587         r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN, "\t%s:%d", pretty_filename(file), line);
 588         if (r < 0) rb_bug("ruby_debug_log returns %d", r);
 589         len += r;
 590     }
 591
 592     rb_execution_context_t *ec = rb_current_execution_context(false);
 593
 594     // Ruby location
 595     int ruby_line;
 596     const char *ruby_file = ec ? rb_source_location_cstr(&ruby_line) : NULL;
 597
 598     if (len < MAX_DEBUG_LOG_MESSAGE_LEN) {
 599         if (ruby_file) {
 600             r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\t%s:%d", pretty_filename(ruby_file), ruby_line);
 601         }
 602         else {
 603             r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\t");
 604         }
 605         if (r < 0) rb_bug("ruby_debug_log returns %d", r);
 606         len += r;
 607     }
 608
 609 #ifdef RUBY_NT_SERIAL
 610     // native thread information
 611     if (len < MAX_DEBUG_LOG_MESSAGE_LEN) {
 612         r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\tnt:%d", ruby_nt_serial);
 613         if (r < 0) rb_bug("ruby_debug_log returns %d", r);
 614         len += r;
 615     }
 616 #endif
 617
 618     if (ec) {
 619         rb_thread_t *th = ec ? rb_ec_thread_ptr(ec) : NULL;
 620
 621         // ractor information
 622         if (ruby_single_main_ractor == NULL) {
 623             rb_ractor_t *cr = th ? th->ractor : NULL;
 624             rb_vm_t *vm = GET_VM();
 625
 626             if (r && len < MAX_DEBUG_LOG_MESSAGE_LEN) {
 627                 r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\tr:#%d/%u (%u)",
 628                              cr ? (int)rb_ractor_id(cr) : -1, vm->ractor.cnt, vm->ractor.sched.running_cnt);
 629
 630                 if (r < 0) rb_bug("ruby_debug_log returns %d", r);
 631                 len += r;
 632             }
 633         }
 634
 635         // thread information
 636         if (th && r && len < MAX_DEBUG_LOG_MESSAGE_LEN) {
 637             rb_execution_context_t *rec = th->ractor ? th->ractor->threads.running_ec : NULL;
 638             const rb_thread_t *rth = rec ? rec->thread_ptr : NULL;
 639             const rb_thread_t *sth = th->ractor ? th->ractor->threads.sched.running : NULL;
 640
 641             if (rth != th || sth != th) {
 642                 r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\tth:%u (rth:%d,sth:%d)",
 643                              rb_th_serial(th), rth ? (int)rb_th_serial(rth) : -1, sth ? (int)rb_th_serial(sth) : -1);
 644             }
 645             else {
 646                 r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\tth:%u", rb_th_serial(th));
 647             }
 648             if (r < 0) rb_bug("ruby_debug_log returns %d", r);
 649             len += r;
 650         }
 651     }
 652
 653     rb_nativethread_lock_lock(&debug_log.lock);
 654     {
 655         unsigned int cnt = debug_log.cnt++;
 656
 657         if (ruby_debug_log_mode & ruby_debug_log_memory) {
 658             unsigned int index = cnt % MAX_DEBUG_LOG;
 659             char *dst = RUBY_DEBUG_LOG_MEM_ENTRY(index);
 660             strncpy(dst, buff, MAX_DEBUG_LOG_MESSAGE_LEN);
 661         }
 662         if (ruby_debug_log_mode & ruby_debug_log_stderr) {
 663             fprintf(stderr, "%4u: %s\n", cnt, buff);
 664         }
 665         if (ruby_debug_log_mode & ruby_debug_log_file) {
 666             fprintf(debug_log.output, "%u\t%s\n", cnt, buff);
 667         }
 668     }
 669     rb_nativethread_lock_unlock(&debug_log.lock);
 670 }
 671
 672 // for debugger
 673 static void
 674 debug_log_dump(FILE *out, unsigned int n)
 675 {
 676     if (ruby_debug_log_mode & ruby_debug_log_memory) {
 677         unsigned int size = debug_log.cnt > MAX_DEBUG_LOG ? MAX_DEBUG_LOG : debug_log.cnt;
 678         unsigned int current_index = debug_log.cnt % MAX_DEBUG_LOG;
 679         if (n == 0) n = size;
 680         if (n > size) n = size;
 681
 682         for (unsigned int i=0; i<n; i++) {
 683             int index = current_index - size + i;
 684             if (index < 0) index += MAX_DEBUG_LOG;
 685             VM_ASSERT(index <= MAX_DEBUG_LOG);
 686             const char *mesg = RUBY_DEBUG_LOG_MEM_ENTRY(index);
 687             fprintf(out, "%4u: %s\n", debug_log.cnt - size + i, mesg);
 688         }
 689     }
 690     else {
 691         fprintf(stderr, "RUBY_DEBUG_LOG=mem is not specified.");
 692     }
 693 }
 694
 695 // for debuggers
 696
 697 void
 698 ruby_debug_log_print(unsigned int n)
 699 {
 700     debug_log_dump(stderr, n);
 701 }
 702
 703 void
 704 ruby_debug_log_dump(const char *fname, unsigned int n)
 705 {
 706     FILE *fp = fopen(fname, "w");
 707     if (fp == NULL) {
 708         fprintf(stderr, "can't open %s. give up.\n", fname);
 709     }
 710     else {
 711         debug_log_dump(fp, n);
 712         fclose(fp);
 713     }
 714 }
 715 #endif // #if USE_RUBY_DEBUG_LOG