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_robject_consts    robject_consts;
  57     enum ruby_rmodule_flags     rmodule_flags;
  58     enum ruby_rstring_flags     rstring_flags;
  59 #if !USE_RVARGC
  60     enum ruby_rstring_consts    rstring_consts;
  61 #endif
  62     enum ruby_rarray_flags      rarray_flags;
  63     enum ruby_rarray_consts     rarray_consts;
  64     enum {
  65         RUBY_FMODE_READABLE             = FMODE_READABLE,
  66         RUBY_FMODE_WRITABLE             = FMODE_WRITABLE,
  67         RUBY_FMODE_READWRITE            = FMODE_READWRITE,
  68         RUBY_FMODE_BINMODE              = FMODE_BINMODE,
  69         RUBY_FMODE_SYNC                 = FMODE_SYNC,
  70         RUBY_FMODE_TTY                  = FMODE_TTY,
  71         RUBY_FMODE_DUPLEX               = FMODE_DUPLEX,
  72         RUBY_FMODE_APPEND               = FMODE_APPEND,
  73         RUBY_FMODE_CREATE               = FMODE_CREATE,
  74         RUBY_FMODE_NOREVLOOKUP          = 0x00000100,
  75         RUBY_FMODE_TRUNC                = FMODE_TRUNC,
  76         RUBY_FMODE_TEXTMODE             = FMODE_TEXTMODE,
  77         RUBY_FMODE_PREP                 = 0x00010000,
  78         RUBY_FMODE_SETENC_BY_BOM        = FMODE_SETENC_BY_BOM,
  79         RUBY_FMODE_UNIX                 = 0x00200000,
  80         RUBY_FMODE_INET                 = 0x00400000,
  81         RUBY_FMODE_INET6                = 0x00800000,
  82
  83         RUBY_NODE_TYPESHIFT = NODE_TYPESHIFT,
  84         RUBY_NODE_TYPEMASK  = NODE_TYPEMASK,
  85         RUBY_NODE_LSHIFT    = NODE_LSHIFT,
  86         RUBY_NODE_FL_NEWLINE   = NODE_FL_NEWLINE
  87     } various;
  88     union {
  89         enum imemo_type                     types;
  90         enum {RUBY_IMEMO_MASK = IMEMO_MASK} mask;
  91         struct RIMemo                      *ptr;
  92     } imemo;
  93     struct RSymbol *symbol_ptr;
  94     enum vm_call_flag_bits vm_call_flags;
  95 } ruby_dummy_gdb_enums;
  96
  97 const SIGNED_VALUE RUBY_NODE_LMASK = NODE_LMASK;
  98
  99 int
 100 ruby_debug_print_indent(int level, int debug_level, int indent_level)
 101 {
 102     if (level < debug_level) {
 103         fprintf(stderr, "%*s", indent_level, "");
 104         fflush(stderr);
 105         return TRUE;
 106     }
 107     return FALSE;
 108 }
 109
 110 void
 111 ruby_debug_printf(const char *format, ...)
 112 {
 113     va_list ap;
 114     va_start(ap, format);
 115     vfprintf(stderr, format, ap);
 116     va_end(ap);
 117 }
 118
 119 #include "gc.h"
 120
 121 VALUE
 122 ruby_debug_print_value(int level, int debug_level, const char *header, VALUE obj)
 123 {
 124     if (level < debug_level) {
 125         char buff[0x100];
 126         rb_raw_obj_info(buff, 0x100, obj);
 127
 128         fprintf(stderr, "DBG> %s: %s\n", header, buff);
 129         fflush(stderr);
 130     }
 131     return obj;
 132 }
 133
 134 void
 135 ruby_debug_print_v(VALUE v)
 136 {
 137     ruby_debug_print_value(0, 1, "", v);
 138 }
 139
 140 ID
 141 ruby_debug_print_id(int level, int debug_level, const char *header, ID id)
 142 {
 143     if (level < debug_level) {
 144         fprintf(stderr, "DBG> %s: %s\n", header, rb_id2name(id));
 145         fflush(stderr);
 146     }
 147     return id;
 148 }
 149
 150 NODE *
 151 ruby_debug_print_node(int level, int debug_level, const char *header, const NODE *node)
 152 {
 153     if (level < debug_level) {
 154         fprintf(stderr, "DBG> %s: %s (%u)\n", header,
 155                 ruby_node_name(nd_type(node)), nd_line(node));
 156     }
 157     return (NODE *)node;
 158 }
 159
 160 void
 161 ruby_debug_breakpoint(void)
 162 {
 163     /* */
 164 }
 165
 166 #if defined _WIN32
 167 # if RUBY_MSVCRT_VERSION >= 80
 168 extern int ruby_w32_rtc_error;
 169 # endif
 170 #endif
 171 #if defined _WIN32 || defined __CYGWIN__
 172 #include <windows.h>
 173 UINT ruby_w32_codepage[2];
 174 #endif
 175 extern int ruby_rgengc_debug;
 176 extern int ruby_on_ci;
 177
 178 int
 179 ruby_env_debug_option(const char *str, int len, void *arg)
 180 {
 181     int ov;
 182     size_t retlen;
 183     unsigned long n;
 184 #define SET_WHEN(name, var, val) do {       \
 185         if (len == sizeof(name) - 1 &&      \
 186             strncmp(str, (name), len) == 0) { \
 187             (var) = (val);                  \
 188             return 1;                       \
 189         }                                   \
 190     } while (0)
 191 #define NAME_MATCH_VALUE(name)                          \
 192     ((size_t)len >= sizeof(name)-1 &&                   \
 193      strncmp(str, (name), sizeof(name)-1) == 0 &&       \
 194      ((len == sizeof(name)-1 && !(len = 0)) ||          \
 195       (str[sizeof(name)-1] == '=' &&                    \
 196        (str += sizeof(name), len -= sizeof(name), 1))))
 197 #define SET_UINT(val) do { \
 198         n = ruby_scan_digits(str, len, 10, &retlen, &ov); \
 199         if (!ov && retlen) { \
 200             val = (unsigned int)n; \
 201         } \
 202         str += retlen; \
 203         len -= retlen; \
 204     } while (0)
 205 #define SET_UINT_LIST(name, vals, num) do { \
 206         int i; \
 207         for (i = 0; i < (num); ++i) { \
 208             SET_UINT((vals)[i]); \
 209             if (!len || *str != ':') break; \
 210             ++str; \
 211             --len; \
 212         } \
 213         if (len > 0) { \
 214             fprintf(stderr, "ignored "name" option: `%.*s'\n", len, str); \
 215         } \
 216     } while (0)
 217 #define SET_WHEN_UINT(name, vals, num, req) \
 218     if (NAME_MATCH_VALUE(name)) SET_UINT_LIST(name, vals, num);
 219
 220     SET_WHEN("gc_stress", *ruby_initial_gc_stress_ptr, Qtrue);
 221     SET_WHEN("core", ruby_enable_coredump, 1);
 222     SET_WHEN("ci", ruby_on_ci, 1);
 223     if (NAME_MATCH_VALUE("rgengc")) {
 224         if (!len) ruby_rgengc_debug = 1;
 225         else SET_UINT_LIST("rgengc", &ruby_rgengc_debug, 1);
 226         return 1;
 227     }
 228 #if defined _WIN32
 229 # if RUBY_MSVCRT_VERSION >= 80
 230     SET_WHEN("rtc_error", ruby_w32_rtc_error, 1);
 231 # endif
 232 #endif
 233 #if defined _WIN32 || defined __CYGWIN__
 234     if (NAME_MATCH_VALUE("codepage")) {
 235         if (!len) fprintf(stderr, "missing codepage argument");
 236         else SET_UINT_LIST("codepage", ruby_w32_codepage, numberof(ruby_w32_codepage));
 237         return 1;
 238     }
 239 #endif
 240     return 0;
 241 }
 242
 243 static void
 244 set_debug_option(const char *str, int len, void *arg)
 245 {
 246     if (!ruby_env_debug_option(str, len, arg)) {
 247         fprintf(stderr, "unexpected debug option: %.*s\n", len, str);
 248     }
 249 }
 250
 251 #if USE_RUBY_DEBUG_LOG
 252 static void setup_debug_log(void);
 253 #else
 254 #define setup_debug_log()
 255 #endif
 256
 257 void
 258 ruby_set_debug_option(const char *str)
 259 {
 260     ruby_each_words(str, set_debug_option, 0);
 261     setup_debug_log();
 262 }
 263
 264 #if USE_RUBY_DEBUG_LOG
 265
 266 // RUBY_DEBUG_LOG features
 267 // See vm_debug.h comments for details.
 268
 269 #define MAX_DEBUG_LOG             0x1000
 270 #define MAX_DEBUG_LOG_MESSAGE_LEN 0x0200
 271 #define MAX_DEBUG_LOG_FILTER      0x0010
 272
 273 enum ruby_debug_log_mode ruby_debug_log_mode;
 274
 275 static struct {
 276     char *mem;
 277     unsigned int cnt;
 278     char filters[MAX_DEBUG_LOG_FILTER][MAX_DEBUG_LOG_FILTER];
 279     unsigned int filters_num;
 280     rb_nativethread_lock_t lock;
 281     FILE *output;
 282 } debug_log;
 283
 284 static char *
 285 RUBY_DEBUG_LOG_MEM_ENTRY(unsigned int index)
 286 {
 287     return &debug_log.mem[MAX_DEBUG_LOG_MESSAGE_LEN * index];
 288 }
 289
 290 static void
 291 setup_debug_log(void)
 292 {
 293     // check RUBY_DEBUG_LOG
 294     const char *log_config = getenv("RUBY_DEBUG_LOG");
 295     if (log_config) {
 296         fprintf(stderr, "RUBY_DEBUG_LOG=%s\n", log_config);
 297
 298         if  (strcmp(log_config, "mem") == 0) {
 299             debug_log.mem = (char *)malloc(MAX_DEBUG_LOG * MAX_DEBUG_LOG_MESSAGE_LEN);
 300             if (debug_log.mem == NULL) {
 301                 fprintf(stderr, "setup_debug_log failed (can't allocate memory)\n");
 302                 exit(1);
 303             }
 304             ruby_debug_log_mode |= ruby_debug_log_memory;
 305         }
 306         else if (strcmp(log_config, "stderr") == 0) {
 307             ruby_debug_log_mode |= ruby_debug_log_stderr;
 308         }
 309         else {
 310             ruby_debug_log_mode |= ruby_debug_log_file;
 311             if ((debug_log.output = fopen(log_config, "w")) == NULL) {
 312                 fprintf(stderr, "can not open %s for RUBY_DEBUG_LOG\n", log_config);
 313                 exit(1);
 314             }
 315             setvbuf(debug_log.output, NULL, _IONBF, 0);
 316         }
 317
 318         rb_nativethread_lock_initialize(&debug_log.lock);
 319     }
 320
 321     // check RUBY_DEBUG_LOG_FILTER
 322     const char *filter_config = getenv("RUBY_DEBUG_LOG_FILTER");
 323     if (filter_config && strlen(filter_config) > 0) {
 324         unsigned int i;
 325         for (i=0; i<MAX_DEBUG_LOG_FILTER; i++) {
 326             const char *p;
 327             if ((p = strchr(filter_config, ',')) == NULL) {
 328                 if (strlen(filter_config) >= MAX_DEBUG_LOG_FILTER) {
 329                     fprintf(stderr, "too long: %s (max:%d)\n", filter_config, MAX_DEBUG_LOG_FILTER);
 330                     exit(1);
 331                 }
 332                 strncpy(debug_log.filters[i], filter_config, MAX_DEBUG_LOG_FILTER - 1);
 333                 i++;
 334                 break;
 335             }
 336             else {
 337                 size_t n = p - filter_config;
 338                 if (n >= MAX_DEBUG_LOG_FILTER) {
 339                     fprintf(stderr, "too long: %s (max:%d)\n", filter_config, MAX_DEBUG_LOG_FILTER);
 340                     exit(1);
 341                 }
 342                 strncpy(debug_log.filters[i], filter_config, n);
 343                 filter_config = p+1;
 344             }
 345         }
 346         debug_log.filters_num = i;
 347         for (i=0; i<debug_log.filters_num; i++) {
 348             fprintf(stderr, "RUBY_DEBUG_LOG_FILTER[%d]=%s\n", i, debug_log.filters[i]);
 349         }
 350     }
 351 }
 352
 353 bool
 354 ruby_debug_log_filter(const char *func_name)
 355 {
 356     if (debug_log.filters_num > 0) {
 357         for (unsigned int i = 0; i<debug_log.filters_num; i++) {
 358             if (strstr(func_name, debug_log.filters[i]) != NULL) {
 359                 return true;
 360             }
 361         }
 362         return false;
 363     }
 364     else {
 365         return true;
 366     }
 367 }
 368
 369 static const char *
 370 pretty_filename(const char *path)
 371 {
 372     // basename is one idea.
 373     const char *s;
 374     while ((s = strchr(path, '/')) != NULL) {
 375         path = s+1;
 376     }
 377     return path;
 378 }
 379
 380 void
 381 ruby_debug_log(const char *file, int line, const char *func_name, const char *fmt, ...)
 382 {
 383     char buff[MAX_DEBUG_LOG_MESSAGE_LEN] = {0};
 384     int len = 0;
 385     int r = 0;
 386
 387     // message title
 388     if (func_name && len < MAX_DEBUG_LOG_MESSAGE_LEN) {
 389         r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN, "%s\t", func_name);
 390         if (r < 0) rb_bug("ruby_debug_log returns %d\n", r);
 391         len += r;
 392     }
 393
 394     // message
 395     if (fmt && len < MAX_DEBUG_LOG_MESSAGE_LEN) {
 396         va_list args;
 397         va_start(args, fmt);
 398         r = vsnprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, fmt, args);
 399         va_end(args);
 400         if (r < 0) rb_bug("ruby_debug_log vsnprintf() returns %d", r);
 401         len += r;
 402     }
 403
 404     // optional information
 405
 406     // C location
 407     if (file && len < MAX_DEBUG_LOG_MESSAGE_LEN) {
 408         r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN, "\t%s:%d", pretty_filename(file), line);
 409         if (r < 0) rb_bug("ruby_debug_log returns %d\n", r);
 410         len += r;
 411     }
 412
 413     // Ruby location
 414     int ruby_line;
 415     const char *ruby_file = rb_source_location_cstr(&ruby_line);
 416     if (len < MAX_DEBUG_LOG_MESSAGE_LEN) {
 417         if (ruby_file) {
 418             r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\t%s:%d", pretty_filename(ruby_file), ruby_line);
 419         }
 420         else {
 421             r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\t");
 422         }
 423         if (r < 0) rb_bug("ruby_debug_log returns %d\n", r);
 424         len += r;
 425     }
 426
 427     // ractor information
 428     if (ruby_single_main_ractor == NULL) {
 429         rb_ractor_t *cr = GET_RACTOR();
 430         if (r && len < MAX_DEBUG_LOG_MESSAGE_LEN) {
 431             r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\tr:#%u/%u",
 432                          (unsigned int)rb_ractor_id(cr), GET_VM()->ractor.cnt);
 433             if (r < 0) rb_bug("ruby_debug_log returns %d\n", r);
 434             len += r;
 435         }
 436     }
 437
 438     // thread information
 439     if (!rb_thread_alone()) {
 440         const rb_thread_t *th = GET_THREAD();
 441         if (r && len < MAX_DEBUG_LOG_MESSAGE_LEN) {
 442             r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\tth:%p", (void *)th);
 443             if (r < 0) rb_bug("ruby_debug_log returns %d\n", r);
 444             len += r;
 445         }
 446     }
 447
 448     rb_nativethread_lock_lock(&debug_log.lock);
 449     {
 450         unsigned int cnt = debug_log.cnt++;
 451
 452         if (ruby_debug_log_mode & ruby_debug_log_memory) {
 453             unsigned int index = cnt % MAX_DEBUG_LOG;
 454             char *dst = RUBY_DEBUG_LOG_MEM_ENTRY(index);
 455             strncpy(dst, buff, MAX_DEBUG_LOG_MESSAGE_LEN);
 456         }
 457         if (ruby_debug_log_mode & ruby_debug_log_stderr) {
 458             fprintf(stderr, "%4u: %s\n", cnt, buff);
 459         }
 460         if (ruby_debug_log_mode & ruby_debug_log_file) {
 461             fprintf(debug_log.output, "%u\t%s\n", cnt, buff);
 462         }
 463     }
 464     rb_nativethread_lock_unlock(&debug_log.lock);
 465 }
 466
 467 // for debugger
 468 static void
 469 debug_log_dump(FILE *out, unsigned int n)
 470 {
 471     if (ruby_debug_log_mode & ruby_debug_log_memory) {
 472         unsigned int size = debug_log.cnt > MAX_DEBUG_LOG ? MAX_DEBUG_LOG : debug_log.cnt;
 473         unsigned int current_index = debug_log.cnt % MAX_DEBUG_LOG;
 474         if (n == 0) n = size;
 475         if (n > size) n = size;
 476
 477         for (unsigned int i=0; i<n; i++) {
 478             int index = current_index - size + i;
 479             if (index < 0) index += MAX_DEBUG_LOG;
 480             VM_ASSERT(index <= MAX_DEBUG_LOG);
 481             const char *mesg = RUBY_DEBUG_LOG_MEM_ENTRY(index);;
 482             fprintf(out, "%4u: %s\n", debug_log.cnt - size + i, mesg);
 483         }
 484     }
 485     else {
 486         fprintf(stderr, "RUBY_DEBUG_LOG=mem is not specified.");
 487     }
 488 }
 489
 490 // for debuggers
 491
 492 void
 493 ruby_debug_log_print(unsigned int n)
 494 {
 495     debug_log_dump(stderr, n);
 496 }
 497
 498 void
 499 ruby_debug_log_dump(const char *fname, unsigned int n)
 500 {
 501     FILE *fp = fopen(fname, "w");
 502     if (fp == NULL) {
 503         fprintf(stderr, "can't open %s. give up.\n", fname);
 504     }
 505     else {
 506         debug_log_dump(fp, n);
 507         fclose(fp);
 508     }
 509 }
 510 #endif // #if USE_RUBY_DEBUG_LOG