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 #ifdef USE_RUBY_DEBUG_LOG
 252 STATIC_ASSERT(USE_RUBY_DEBUG_LOG, USE_RUBY_DEBUG_LOG ? RUBY_DEVEL : 1);
 253 #endif
 254
 255 #if RUBY_DEVEL
 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 RUBY_DEVEL
 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      0x0010
 276
 277 enum ruby_debug_log_mode ruby_debug_log_mode;
 278
 279 static struct {
 280     char *mem;
 281     unsigned int cnt;
 282     char filters[MAX_DEBUG_LOG_FILTER][MAX_DEBUG_LOG_FILTER];
 283     unsigned int filters_num;
 284     rb_nativethread_lock_t lock;
 285     FILE *output;
 286 } debug_log;
 287
 288 static char *
 289 RUBY_DEBUG_LOG_MEM_ENTRY(unsigned int index)
 290 {
 291     return &debug_log.mem[MAX_DEBUG_LOG_MESSAGE_LEN * index];
 292 }
 293
 294 static void
 295 setup_debug_log(void)
 296 {
 297     // check RUBY_DEBUG_LOG
 298     const char *log_config = getenv("RUBY_DEBUG_LOG");
 299     if (log_config) {
 300         fprintf(stderr, "RUBY_DEBUG_LOG=%s\n", log_config);
 301
 302         if  (strcmp(log_config, "mem") == 0) {
 303             debug_log.mem = (char *)malloc(MAX_DEBUG_LOG * MAX_DEBUG_LOG_MESSAGE_LEN);
 304             if (debug_log.mem == NULL) {
 305                 fprintf(stderr, "setup_debug_log failed (can't allocate memory)\n");
 306                 exit(1);
 307             }
 308             ruby_debug_log_mode |= ruby_debug_log_memory;
 309         }
 310         else if (strcmp(log_config, "stderr") == 0) {
 311             ruby_debug_log_mode |= ruby_debug_log_stderr;
 312         }
 313         else {
 314             ruby_debug_log_mode |= ruby_debug_log_file;
 315             if ((debug_log.output = fopen(log_config, "w")) == NULL) {
 316                 fprintf(stderr, "can not open %s for RUBY_DEBUG_LOG\n", log_config);
 317                 exit(1);
 318             }
 319             setvbuf(debug_log.output, NULL, _IONBF, 0);
 320         }
 321
 322         rb_nativethread_lock_initialize(&debug_log.lock);
 323     }
 324
 325     // check RUBY_DEBUG_LOG_FILTER
 326     const char *filter_config = getenv("RUBY_DEBUG_LOG_FILTER");
 327     if (filter_config && strlen(filter_config) > 0) {
 328         unsigned int i;
 329         for (i=0; i<MAX_DEBUG_LOG_FILTER; i++) {
 330             const char *p;
 331             if ((p = strchr(filter_config, ',')) == NULL) {
 332                 if (strlen(filter_config) >= MAX_DEBUG_LOG_FILTER) {
 333                     fprintf(stderr, "too long: %s (max:%d)\n", filter_config, MAX_DEBUG_LOG_FILTER);
 334                     exit(1);
 335                 }
 336                 strncpy(debug_log.filters[i], filter_config, MAX_DEBUG_LOG_FILTER - 1);
 337                 i++;
 338                 break;
 339             }
 340             else {
 341                 size_t n = p - filter_config;
 342                 if (n >= MAX_DEBUG_LOG_FILTER) {
 343                     fprintf(stderr, "too long: %s (max:%d)\n", filter_config, MAX_DEBUG_LOG_FILTER);
 344                     exit(1);
 345                 }
 346                 strncpy(debug_log.filters[i], filter_config, n);
 347                 filter_config = p+1;
 348             }
 349         }
 350         debug_log.filters_num = i;
 351         for (i=0; i<debug_log.filters_num; i++) {
 352             fprintf(stderr, "RUBY_DEBUG_LOG_FILTER[%d]=%s\n", i, debug_log.filters[i]);
 353         }
 354     }
 355 }
 356
 357 bool
 358 ruby_debug_log_filter(const char *func_name)
 359 {
 360     if (debug_log.filters_num > 0) {
 361         for (unsigned int i = 0; i<debug_log.filters_num; i++) {
 362             if (strstr(func_name, debug_log.filters[i]) != NULL) {
 363                 return true;
 364             }
 365         }
 366         return false;
 367     }
 368     else {
 369         return true;
 370     }
 371 }
 372
 373 static const char *
 374 pretty_filename(const char *path)
 375 {
 376     // basename is one idea.
 377     const char *s;
 378     while ((s = strchr(path, '/')) != NULL) {
 379         path = s+1;
 380     }
 381     return path;
 382 }
 383
 384 void
 385 ruby_debug_log(const char *file, int line, const char *func_name, const char *fmt, ...)
 386 {
 387     char buff[MAX_DEBUG_LOG_MESSAGE_LEN] = {0};
 388     int len = 0;
 389     int r = 0;
 390
 391     // message title
 392     if (func_name && len < MAX_DEBUG_LOG_MESSAGE_LEN) {
 393         r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN, "%s\t", func_name);
 394         if (r < 0) rb_bug("ruby_debug_log returns %d\n", r);
 395         len += r;
 396     }
 397
 398     // message
 399     if (fmt && len < MAX_DEBUG_LOG_MESSAGE_LEN) {
 400         va_list args;
 401         va_start(args, fmt);
 402         r = vsnprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, fmt, args);
 403         va_end(args);
 404         if (r < 0) rb_bug("ruby_debug_log vsnprintf() returns %d", r);
 405         len += r;
 406     }
 407
 408     // optional information
 409
 410     // C location
 411     if (file && len < MAX_DEBUG_LOG_MESSAGE_LEN) {
 412         r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN, "\t%s:%d", pretty_filename(file), line);
 413         if (r < 0) rb_bug("ruby_debug_log returns %d\n", r);
 414         len += r;
 415     }
 416
 417     // Ruby location
 418     int ruby_line;
 419     const char *ruby_file = rb_source_location_cstr(&ruby_line);
 420     if (len < MAX_DEBUG_LOG_MESSAGE_LEN) {
 421         if (ruby_file) {
 422             r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\t%s:%d", pretty_filename(ruby_file), ruby_line);
 423         }
 424         else {
 425             r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\t");
 426         }
 427         if (r < 0) rb_bug("ruby_debug_log returns %d\n", r);
 428         len += r;
 429     }
 430
 431     // ractor information
 432     if (ruby_single_main_ractor == NULL) {
 433         rb_ractor_t *cr = GET_RACTOR();
 434         if (r && len < MAX_DEBUG_LOG_MESSAGE_LEN) {
 435             r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\tr:#%u/%u",
 436                          (unsigned int)rb_ractor_id(cr), GET_VM()->ractor.cnt);
 437             if (r < 0) rb_bug("ruby_debug_log returns %d\n", r);
 438             len += r;
 439         }
 440     }
 441
 442     // thread information
 443     if (!rb_thread_alone()) {
 444         const rb_thread_t *th = GET_THREAD();
 445         if (r && len < MAX_DEBUG_LOG_MESSAGE_LEN) {
 446             r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\tth:%p", (void *)th);
 447             if (r < 0) rb_bug("ruby_debug_log returns %d\n", r);
 448             len += r;
 449         }
 450     }
 451
 452     rb_nativethread_lock_lock(&debug_log.lock);
 453     {
 454         unsigned int cnt = debug_log.cnt++;
 455
 456         if (ruby_debug_log_mode & ruby_debug_log_memory) {
 457             unsigned int index = cnt % MAX_DEBUG_LOG;
 458             char *dst = RUBY_DEBUG_LOG_MEM_ENTRY(index);
 459             strncpy(dst, buff, MAX_DEBUG_LOG_MESSAGE_LEN);
 460         }
 461         if (ruby_debug_log_mode & ruby_debug_log_stderr) {
 462             fprintf(stderr, "%4u: %s\n", cnt, buff);
 463         }
 464         if (ruby_debug_log_mode & ruby_debug_log_file) {
 465             fprintf(debug_log.output, "%u\t%s\n", cnt, buff);
 466         }
 467     }
 468     rb_nativethread_lock_unlock(&debug_log.lock);
 469 }
 470
 471 // for debugger
 472 static void
 473 debug_log_dump(FILE *out, unsigned int n)
 474 {
 475     if (ruby_debug_log_mode & ruby_debug_log_memory) {
 476         unsigned int size = debug_log.cnt > MAX_DEBUG_LOG ? MAX_DEBUG_LOG : debug_log.cnt;
 477         unsigned int current_index = debug_log.cnt % MAX_DEBUG_LOG;
 478         if (n == 0) n = size;
 479         if (n > size) n = size;
 480
 481         for (unsigned int i=0; i<n; i++) {
 482             int index = current_index - size + i;
 483             if (index < 0) index += MAX_DEBUG_LOG;
 484             VM_ASSERT(index <= MAX_DEBUG_LOG);
 485             const char *mesg = RUBY_DEBUG_LOG_MEM_ENTRY(index);;
 486             fprintf(out, "%4u: %s\n", debug_log.cnt - size + i, mesg);
 487         }
 488     }
 489     else {
 490         fprintf(stderr, "RUBY_DEBUG_LOG=mem is not specified.");
 491     }
 492 }
 493
 494 // for debuggers
 495
 496 void
 497 ruby_debug_log_print(unsigned int n)
 498 {
 499     debug_log_dump(stderr, n);
 500 }
 501
 502 void
 503 ruby_debug_log_dump(const char *fname, unsigned int n)
 504 {
 505     FILE *fp = fopen(fname, "w");
 506     if (fp == NULL) {
 507         fprintf(stderr, "can't open %s. give up.\n", fname);
 508     }
 509     else {
 510         debug_log_dump(fp, n);
 511         fclose(fp);
 512     }
 513 }
 514 #endif // #if RUBY_DEVEL