diff options
Diffstat (limited to 'debug.c')
| -rw-r--r-- | debug.c | 280 |
1 files changed, 183 insertions, 97 deletions
@@ -53,32 +53,28 @@ const union { rb_econv_result_t econv_result; enum ruby_preserved_encindex encoding_index; enum ruby_robject_flags robject_flags; - enum ruby_robject_consts robject_consts; enum ruby_rmodule_flags rmodule_flags; enum ruby_rstring_flags rstring_flags; -#if !USE_RVARGC - enum ruby_rstring_consts rstring_consts; -#endif enum ruby_rarray_flags rarray_flags; enum ruby_rarray_consts rarray_consts; enum { - RUBY_FMODE_READABLE = FMODE_READABLE, - RUBY_FMODE_WRITABLE = FMODE_WRITABLE, - RUBY_FMODE_READWRITE = FMODE_READWRITE, - RUBY_FMODE_BINMODE = FMODE_BINMODE, - RUBY_FMODE_SYNC = FMODE_SYNC, - RUBY_FMODE_TTY = FMODE_TTY, - RUBY_FMODE_DUPLEX = FMODE_DUPLEX, - RUBY_FMODE_APPEND = FMODE_APPEND, - RUBY_FMODE_CREATE = FMODE_CREATE, - RUBY_FMODE_NOREVLOOKUP = 0x00000100, - RUBY_FMODE_TRUNC = FMODE_TRUNC, - RUBY_FMODE_TEXTMODE = FMODE_TEXTMODE, - RUBY_FMODE_PREP = 0x00010000, - RUBY_FMODE_SETENC_BY_BOM = FMODE_SETENC_BY_BOM, - RUBY_FMODE_UNIX = 0x00200000, - RUBY_FMODE_INET = 0x00400000, - RUBY_FMODE_INET6 = 0x00800000, + RUBY_FMODE_READABLE = FMODE_READABLE, + RUBY_FMODE_WRITABLE = FMODE_WRITABLE, + RUBY_FMODE_READWRITE = FMODE_READWRITE, + RUBY_FMODE_BINMODE = FMODE_BINMODE, + RUBY_FMODE_SYNC = FMODE_SYNC, + RUBY_FMODE_TTY = FMODE_TTY, + RUBY_FMODE_DUPLEX = FMODE_DUPLEX, + RUBY_FMODE_APPEND = FMODE_APPEND, + RUBY_FMODE_CREATE = FMODE_CREATE, + RUBY_FMODE_NOREVLOOKUP = 0x00000100, + RUBY_FMODE_TRUNC = FMODE_TRUNC, + RUBY_FMODE_TEXTMODE = FMODE_TEXTMODE, + RUBY_FMODE_EXTERNAL = 0x00010000, + RUBY_FMODE_SETENC_BY_BOM = FMODE_SETENC_BY_BOM, + RUBY_FMODE_UNIX = 0x00200000, + RUBY_FMODE_INET = 0x00400000, + RUBY_FMODE_INET6 = 0x00800000, RUBY_NODE_TYPESHIFT = NODE_TYPESHIFT, RUBY_NODE_TYPEMASK = NODE_TYPEMASK, @@ -86,9 +82,9 @@ const union { RUBY_NODE_FL_NEWLINE = NODE_FL_NEWLINE } various; union { - enum imemo_type types; - enum {RUBY_IMEMO_MASK = IMEMO_MASK} mask; - struct RIMemo *ptr; + enum imemo_type types; + enum {RUBY_IMEMO_MASK = IMEMO_MASK} mask; + struct RIMemo *ptr; } imemo; struct RSymbol *symbol_ptr; enum vm_call_flag_bits vm_call_flags; @@ -100,9 +96,9 @@ int ruby_debug_print_indent(int level, int debug_level, int indent_level) { if (level < debug_level) { - fprintf(stderr, "%*s", indent_level, ""); - fflush(stderr); - return TRUE; + fprintf(stderr, "%*s", indent_level, ""); + fflush(stderr); + return TRUE; } return FALSE; } @@ -116,17 +112,17 @@ ruby_debug_printf(const char *format, ...) va_end(ap); } -#include "gc.h" +#include "internal/gc.h" VALUE ruby_debug_print_value(int level, int debug_level, const char *header, VALUE obj) { if (level < debug_level) { - char buff[0x100]; - rb_raw_obj_info(buff, 0x100, obj); + char buff[0x100]; + rb_raw_obj_info(buff, 0x100, obj); - fprintf(stderr, "DBG> %s: %s\n", header, buff); - fflush(stderr); + fprintf(stderr, "DBG> %s: %s\n", header, buff); + fflush(stderr); } return obj; } @@ -141,8 +137,8 @@ ID ruby_debug_print_id(int level, int debug_level, const char *header, ID id) { if (level < debug_level) { - fprintf(stderr, "DBG> %s: %s\n", header, rb_id2name(id)); - fflush(stderr); + fprintf(stderr, "DBG> %s: %s\n", header, rb_id2name(id)); + fflush(stderr); } return id; } @@ -151,13 +147,21 @@ NODE * ruby_debug_print_node(int level, int debug_level, const char *header, const NODE *node) { if (level < debug_level) { - fprintf(stderr, "DBG> %s: %s (%u)\n", header, - ruby_node_name(nd_type(node)), nd_line(node)); + fprintf(stderr, "DBG> %s: %s (id: %d, line: %d, location: (%d,%d)-(%d,%d))\n", + header, ruby_node_name(nd_type(node)), nd_node_id(node), nd_line(node), + nd_first_lineno(node), nd_first_column(node), + nd_last_lineno(node), nd_last_column(node)); } return (NODE *)node; } void +ruby_debug_print_n(const NODE *node) +{ + ruby_debug_print_node(0, 1, "", node); +} + +void ruby_debug_breakpoint(void) { /* */ @@ -181,12 +185,12 @@ ruby_env_debug_option(const char *str, int len, void *arg) int ov; size_t retlen; unsigned long n; +#define NAME_MATCH(name) (len == sizeof(name) - 1 && strncmp(str, (name), len) == 0) #define SET_WHEN(name, var, val) do { \ - if (len == sizeof(name) - 1 && \ - strncmp(str, (name), len) == 0) { \ - (var) = (val); \ - return 1; \ - } \ + if (NAME_MATCH(name)) { \ + (var) = (val); \ + return 1; \ + } \ } while (0) #define NAME_MATCH_VALUE(name) \ ((size_t)len >= sizeof(name)-1 && \ @@ -195,47 +199,47 @@ ruby_env_debug_option(const char *str, int len, void *arg) (str[sizeof(name)-1] == '=' && \ (str += sizeof(name), len -= sizeof(name), 1)))) #define SET_UINT(val) do { \ - n = ruby_scan_digits(str, len, 10, &retlen, &ov); \ - if (!ov && retlen) { \ - val = (unsigned int)n; \ - } \ - str += retlen; \ - len -= retlen; \ + n = ruby_scan_digits(str, len, 10, &retlen, &ov); \ + if (!ov && retlen) { \ + val = (unsigned int)n; \ + } \ + str += retlen; \ + len -= retlen; \ } while (0) #define SET_UINT_LIST(name, vals, num) do { \ - int i; \ - for (i = 0; i < (num); ++i) { \ - SET_UINT((vals)[i]); \ - if (!len || *str != ':') break; \ - ++str; \ - --len; \ - } \ - if (len > 0) { \ - fprintf(stderr, "ignored "name" option: `%.*s'\n", len, str); \ - } \ + int i; \ + for (i = 0; i < (num); ++i) { \ + SET_UINT((vals)[i]); \ + if (!len || *str != ':') break; \ + ++str; \ + --len; \ + } \ + if (len > 0) { \ + fprintf(stderr, "ignored "name" option: '%.*s'\n", len, str); \ + } \ } while (0) #define SET_WHEN_UINT(name, vals, num, req) \ - if (NAME_MATCH_VALUE(name)) SET_UINT_LIST(name, vals, num); + if (NAME_MATCH_VALUE(name)) { \ + if (!len) req; \ + else SET_UINT_LIST(name, vals, num); \ + return 1; \ + } - SET_WHEN("gc_stress", *ruby_initial_gc_stress_ptr, Qtrue); + if (NAME_MATCH("gc_stress")) { + rb_gc_initial_stress_set(Qtrue); + return 1; + } SET_WHEN("core", ruby_enable_coredump, 1); SET_WHEN("ci", ruby_on_ci, 1); - if (NAME_MATCH_VALUE("rgengc")) { - if (!len) ruby_rgengc_debug = 1; - else SET_UINT_LIST("rgengc", &ruby_rgengc_debug, 1); - return 1; - } + SET_WHEN_UINT("rgengc", &ruby_rgengc_debug, 1, ruby_rgengc_debug = 1); #if defined _WIN32 # if RUBY_MSVCRT_VERSION >= 80 SET_WHEN("rtc_error", ruby_w32_rtc_error, 1); # endif #endif #if defined _WIN32 || defined __CYGWIN__ - if (NAME_MATCH_VALUE("codepage")) { - if (!len) fprintf(stderr, "missing codepage argument"); - else SET_UINT_LIST("codepage", ruby_w32_codepage, numberof(ruby_w32_codepage)); - return 1; - } + SET_WHEN_UINT("codepage", ruby_w32_codepage, numberof(ruby_w32_codepage), + fprintf(stderr, "missing codepage argument")); #endif return 0; } @@ -244,7 +248,7 @@ static void set_debug_option(const char *str, int len, void *arg) { if (!ruby_env_debug_option(str, len, arg)) { - fprintf(stderr, "unexpected debug option: %.*s\n", len, str); + fprintf(stderr, "unexpected debug option: %.*s\n", len, str); } } @@ -289,12 +293,20 @@ static const char *dlf_type_names[] = { "func", }; +#ifdef MAX_PATH +#define DEBUG_LOG_MAX_PATH (MAX_PATH-1) +#else +#define DEBUG_LOG_MAX_PATH 255 +#endif + static struct { char *mem; unsigned int cnt; struct debug_log_filter filters[MAX_DEBUG_LOG_FILTER_NUM]; unsigned int filters_num; + bool show_pid; rb_nativethread_lock_t lock; + char output_file[DEBUG_LOG_MAX_PATH+1]; FILE *output; } debug_log; @@ -346,7 +358,8 @@ setup_debug_log_filter(void) if (*str == '-') { debug_log.filters[i].negative = true; str++; - } else if (*str == '+') { + } + else if (*str == '+') { // negative is false on default. str++; } @@ -395,7 +408,39 @@ setup_debug_log(void) } else { ruby_debug_log_mode |= ruby_debug_log_file; - if ((debug_log.output = fopen(log_config, "w")) == NULL) { + + // pid extension with %p + unsigned long len = strlen(log_config); + + for (unsigned long i=0, j=0; i<len; i++) { + const char c = log_config[i]; + + if (c == '%') { + i++; + switch (log_config[i]) { + case '%': + debug_log.output_file[j++] = '%'; + break; + case 'p': + snprintf(debug_log.output_file + j, DEBUG_LOG_MAX_PATH - j, "%d", getpid()); + j = strlen(debug_log.output_file); + break; + default: + fprintf(stderr, "can not parse RUBY_DEBUG_LOG filename: %s\n", log_config); + exit(1); + } + } + else { + debug_log.output_file[j++] = c; + } + + if (j >= DEBUG_LOG_MAX_PATH) { + fprintf(stderr, "RUBY_DEBUG_LOG=%s is too long\n", log_config); + exit(1); + } + } + + if ((debug_log.output = fopen(debug_log.output_file, "w")) == NULL) { fprintf(stderr, "can not open %s for RUBY_DEBUG_LOG\n", log_config); exit(1); } @@ -406,9 +451,17 @@ setup_debug_log(void) (ruby_debug_log_mode & ruby_debug_log_memory) ? "[mem]" : "", (ruby_debug_log_mode & ruby_debug_log_stderr) ? "[stderr]" : "", (ruby_debug_log_mode & ruby_debug_log_file) ? "[file]" : ""); + if (debug_log.output_file[0]) { + fprintf(stderr, "RUBY_DEBUG_LOG filename=%s\n", debug_log.output_file); + } + rb_nativethread_lock_initialize(&debug_log.lock); setup_debug_log_filter(); + + if (getenv("RUBY_DEBUG_LOG_PID")) { + debug_log.show_pid = true; + } } } @@ -447,7 +500,7 @@ check_filter(const char *str, const struct debug_log_filter *filter, bool *state // (func_name or file_name) contains baz or boo // // RUBY_DEBUG_LOG_FILTER=foo,bar,-baz,-boo -// retunrs true if +// returns true if // (func_name or file_name) contains foo or bar // or // (func_name or file_name) doesn't contain baz and @@ -496,6 +549,7 @@ pretty_filename(const char *path) return path; } +#undef ruby_debug_log void ruby_debug_log(const char *file, int line, const char *func_name, const char *fmt, ...) { @@ -503,10 +557,16 @@ ruby_debug_log(const char *file, int line, const char *func_name, const char *fm int len = 0; int r = 0; + if (debug_log.show_pid) { + r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN, "pid:%d\t", getpid()); + if (r < 0) rb_bug("ruby_debug_log returns %d", 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); - if (r < 0) rb_bug("ruby_debug_log returns %d\n", r); + if (r < 0) rb_bug("ruby_debug_log returns %d", r); len += r; } @@ -525,41 +585,67 @@ ruby_debug_log(const char *file, int line, const char *func_name, const char *fm // C location if (file && len < MAX_DEBUG_LOG_MESSAGE_LEN) { r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN, "\t%s:%d", pretty_filename(file), line); - if (r < 0) rb_bug("ruby_debug_log returns %d\n", r); + if (r < 0) rb_bug("ruby_debug_log returns %d", r); len += r; } - if (rb_current_execution_context(false)) { - // Ruby location - int ruby_line; - const char *ruby_file = rb_source_location_cstr(&ruby_line); - if (len < MAX_DEBUG_LOG_MESSAGE_LEN) { - if (ruby_file) { - r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\t%s:%d", pretty_filename(ruby_file), ruby_line); - } - else { - r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\t"); - } - if (r < 0) rb_bug("ruby_debug_log returns %d\n", r); - len += r; + rb_execution_context_t *ec = rb_current_execution_context(false); + + // Ruby location + int ruby_line; + const char *ruby_file = ec ? rb_source_location_cstr(&ruby_line) : NULL; + + if (len < MAX_DEBUG_LOG_MESSAGE_LEN) { + if (ruby_file) { + r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\t%s:%d", pretty_filename(ruby_file), ruby_line); } + else { + r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\t"); + } + if (r < 0) rb_bug("ruby_debug_log returns %d", r); + len += r; + } + +#ifdef RUBY_NT_SERIAL + // native thread information + if (len < MAX_DEBUG_LOG_MESSAGE_LEN) { + r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\tnt:%d", ruby_nt_serial); + if (r < 0) rb_bug("ruby_debug_log returns %d", r); + len += r; + } +#endif + + if (ec) { + rb_thread_t *th = ec ? rb_ec_thread_ptr(ec) : NULL; // ractor information if (ruby_single_main_ractor == NULL) { - rb_ractor_t *cr = GET_RACTOR(); + rb_ractor_t *cr = th ? th->ractor : NULL; + rb_vm_t *vm = GET_VM(); + if (r && len < MAX_DEBUG_LOG_MESSAGE_LEN) { - r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\tr:#%u/%u", - (unsigned int)rb_ractor_id(cr), GET_VM()->ractor.cnt); - if (r < 0) rb_bug("ruby_debug_log returns %d\n", r); + r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\tr:#%d/%u (%u)", + cr ? (int)rb_ractor_id(cr) : -1, vm->ractor.cnt, vm->ractor.sched.running_cnt); + + if (r < 0) rb_bug("ruby_debug_log returns %d", r); len += r; } } // thread information - const rb_thread_t *th = GET_THREAD(); - if (r && len < MAX_DEBUG_LOG_MESSAGE_LEN) { - r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\tth:%u", rb_th_serial(th)); - if (r < 0) rb_bug("ruby_debug_log returns %d\n", r); + if (th && r && len < MAX_DEBUG_LOG_MESSAGE_LEN) { + rb_execution_context_t *rec = th->ractor ? th->ractor->threads.running_ec : NULL; + const rb_thread_t *rth = rec ? rec->thread_ptr : NULL; + const rb_thread_t *sth = th->ractor ? th->ractor->threads.sched.running : NULL; + + if (rth != th || sth != th) { + r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\tth:%u (rth:%d,sth:%d)", + rb_th_serial(th), rth ? (int)rb_th_serial(rth) : -1, sth ? (int)rb_th_serial(sth) : -1); + } + else { + r = snprintf(buff + len, MAX_DEBUG_LOG_MESSAGE_LEN - len, "\tth:%u", rb_th_serial(th)); + } + if (r < 0) rb_bug("ruby_debug_log returns %d", r); len += r; } } @@ -597,7 +683,7 @@ debug_log_dump(FILE *out, unsigned int n) int index = current_index - size + i; if (index < 0) index += MAX_DEBUG_LOG; VM_ASSERT(index <= MAX_DEBUG_LOG); - const char *mesg = RUBY_DEBUG_LOG_MEM_ENTRY(index);; + const char *mesg = RUBY_DEBUG_LOG_MEM_ENTRY(index); fprintf(out, "%4u: %s\n", debug_log.cnt - size + i, mesg); } } |