1
0
Fork 0
mirror of https://github.com/ruby/ruby.git synced 2022-11-09 12:17:21 -05:00

use RUBY_DEBUG_LOG instead of thread_debug

`thread_debug()` was introduced to print debug messages
on `THREAD_DEBUG > 0` but `RUBY_DEBUG_LOG()` is more controllable.
This commit is contained in:
Koichi Sasada 2022-05-24 03:58:18 +09:00
parent f3235ac095
commit 4111028a5c
Notes: git 2022-05-24 10:07:23 +09:00
3 changed files with 128 additions and 192 deletions

202
thread.c
View file

@ -106,10 +106,6 @@
#define RUBY_THREAD_PRIORITY_MIN -3
#endif
#ifndef THREAD_DEBUG
#define THREAD_DEBUG 0
#endif
static VALUE rb_cThreadShield;
static VALUE sym_immediate;
@ -257,60 +253,6 @@ timeout_prepare(rb_hrtime_t **to, rb_hrtime_t *rel, rb_hrtime_t *end,
}
}
#if THREAD_DEBUG
#ifdef HAVE_VA_ARGS_MACRO
void rb_thread_debug(const char *file, int line, const char *fmt, ...);
#define thread_debug(...) rb_thread_debug(__FILE__, __LINE__, __VA_ARGS__)
#define POSITION_FORMAT "%s:%d:"
#define POSITION_ARGS ,file, line
#else
void rb_thread_debug(const char *fmt, ...);
#define thread_debug rb_thread_debug
#define POSITION_FORMAT
#define POSITION_ARGS
#endif
# if THREAD_DEBUG < 0
static int rb_thread_debug_enabled;
/*
* call-seq:
* Thread.DEBUG -> num
*
* Returns the thread debug level. Available only if compiled with
* THREAD_DEBUG=-1.
*/
static VALUE
rb_thread_s_debug(VALUE _)
{
return INT2NUM(rb_thread_debug_enabled);
}
/*
* call-seq:
* Thread.DEBUG = num
*
* Sets the thread debug level. Available only if compiled with
* THREAD_DEBUG=-1.
*/
static VALUE
rb_thread_s_debug_set(VALUE self, VALUE val)
{
rb_thread_debug_enabled = RTEST(val) ? NUM2INT(val) : 0;
return val;
}
# else
# define rb_thread_debug_enabled THREAD_DEBUG
# endif
#else
#define thread_debug if(0)printf
#endif
#define thread_id_str(th) ((void *)(uintptr_t)(th)->nt->thread_id)
#define PRI_THREAD_ID "p"
MAYBE_UNUSED(NOINLINE(static int thread_start_func_2(rb_thread_t *th, VALUE *stack_start)));
void ruby_sigchld_handler(rb_vm_t *); /* signal.c */
@ -335,35 +277,6 @@ ubf_sigwait(void *ignore)
# define USE_EVENTFD (0)
#endif
#if THREAD_DEBUG
static int debug_mutex_initialized = 1;
static rb_nativethread_lock_t debug_mutex;
void
rb_thread_debug(
#ifdef HAVE_VA_ARGS_MACRO
const char *file, int line,
#endif
const char *fmt, ...)
{
va_list args;
char buf[BUFSIZ];
if (!rb_thread_debug_enabled) return;
if (debug_mutex_initialized == 1) {
debug_mutex_initialized = 0;
rb_native_mutex_initialize(&debug_mutex);
}
va_start(args, fmt);
vsnprintf(buf, BUFSIZ, fmt, args);
va_end(args);
DEBUG_OUT();
}
#endif
#include "thread_sync.c"
void
@ -463,15 +376,15 @@ terminate_all(rb_ractor_t *r, const rb_thread_t *main_thread)
ccan_list_for_each(&r->threads.set, th, lt_node) {
if (th != main_thread) {
thread_debug("terminate_all: begin (thid: %"PRI_THREAD_ID", status: %s)\n",
thread_id_str(th), thread_status_name(th, TRUE));
rb_threadptr_pending_interrupt_enque(th, eTerminateSignal);
RUBY_DEBUG_LOG("terminate start th:%u status:%s", rb_th_serial(th), thread_status_name(th, TRUE));
rb_threadptr_pending_interrupt_enque(th, eTerminateSignal);
rb_threadptr_interrupt(th);
thread_debug("terminate_all: end (thid: %"PRI_THREAD_ID", status: %s)\n",
thread_id_str(th), thread_status_name(th, TRUE));
}
RUBY_DEBUG_LOG("terminate done th:%u status:%s", rb_th_serial(th), thread_status_name(th, TRUE));
}
else {
thread_debug("terminate_all: main thread (%p)\n", (void *)th);
RUBY_DEBUG_LOG("main thread th:%u", rb_th_serial(th));
}
}
}
@ -536,8 +449,9 @@ rb_thread_terminate_all(rb_thread_t *th)
EC_PUSH_TAG(ec);
if (EC_EXEC_TAG() == TAG_NONE) {
retry:
thread_debug("rb_thread_terminate_all (main thread: %p)\n", (void *)th);
terminate_all(cr, th);
RUBY_DEBUG_LOG("th:%u", rb_th_serial(th));
terminate_all(cr, th);
while (rb_ractor_living_thread_num(cr) > 1) {
rb_hrtime_t rel = RB_HRTIME_PER_SEC;
@ -730,12 +644,14 @@ thread_start_func_2(rb_thread_t *th, VALUE *stack_start)
VALUE * vm_stack = NULL;
VM_ASSERT(th != th->vm->ractor.main_thread);
thread_debug("thread start: %p\n", (void *)th);
RUBY_DEBUG_LOG("th:%u", rb_th_serial(th));
// setup native thread
thread_sched_to_running(TH_SCHED(th), th);
ruby_thread_set_native(th);
RUBY_DEBUG_LOG("got lock. th:%u", rb_th_serial(th));
// setup ractor
if (rb_ractor_status_p(th->ractor, ractor_blocking)) {
RB_VM_LOCK();
@ -760,8 +676,6 @@ thread_start_func_2(rb_thread_t *th, VALUE *stack_start)
th->ec->machine.stack_start = STACK_DIR_UPPER(vm_stack + size, vm_stack);
th->ec->machine.stack_maxsize -= size * sizeof(VALUE);
thread_debug("thread start (get lock): %p\n", (void *)th);
// Ensure that we are not joinable.
VM_ASSERT(th->value == Qundef);
@ -820,7 +734,7 @@ thread_start_func_2(rb_thread_t *th, VALUE *stack_start)
}
th->status = THREAD_KILLED;
thread_debug("thread end: %p\n", (void *)th);
RUBY_DEBUG_LOG("killed th:%u", rb_th_serial(th));
if (th->vm->ractor.main_thread == th) {
ruby_stop(0);
@ -936,7 +850,7 @@ thread_create_core(VALUE thval, struct thread_create_params *params)
rb_native_mutex_initialize(&th->interrupt_lock);
RUBY_DEBUG_LOG("r:%u th:%p", rb_ractor_id(th->ractor), (void *)th);
RUBY_DEBUG_LOG("r:%u th:%u", rb_ractor_id(th->ractor), rb_th_serial(th));
rb_ractor_living_threads_insert(th->ractor, th);
@ -1138,8 +1052,7 @@ thread_join_sleep(VALUE arg)
}
else {
if (hrtime_update_expire(limit, end)) {
thread_debug("thread_join: timeout (thid: %"PRI_THREAD_ID")\n",
thread_id_str(target_th));
RUBY_DEBUG_LOG("timeout target_th:%u", rb_th_serial(target_th));
return Qfalse;
}
th->status = THREAD_STOPPED;
@ -1147,8 +1060,8 @@ thread_join_sleep(VALUE arg)
}
RUBY_VM_CHECK_INTS_BLOCKING(th->ec);
th->status = THREAD_RUNNABLE;
thread_debug("thread_join: interrupted (thid: %"PRI_THREAD_ID", status: %s)\n",
thread_id_str(target_th), thread_status_name(target_th, TRUE));
RUBY_DEBUG_LOG("interrupted target_th:%u status:%s", rb_th_serial(target_th), thread_status_name(target_th, TRUE));
}
return Qtrue;
}
@ -1168,8 +1081,7 @@ thread_join(rb_thread_t *target_th, VALUE timeout, rb_hrtime_t *limit)
rb_raise(rb_eThreadError, "Target thread must not be main thread");
}
thread_debug("thread_join (thid: %"PRI_THREAD_ID", status: %s)\n",
thread_id_str(target_th), thread_status_name(target_th, TRUE));
RUBY_DEBUG_LOG("target_th:%u status:%s", rb_th_serial(target_th), thread_status_name(target_th, TRUE));
if (target_th->status != THREAD_KILLED) {
struct rb_waiting_list waiter;
@ -1189,8 +1101,7 @@ thread_join(rb_thread_t *target_th, VALUE timeout, rb_hrtime_t *limit)
}
}
thread_debug("thread_join: success (thid: %"PRI_THREAD_ID", status: %s)\n",
thread_id_str(target_th), thread_status_name(target_th, TRUE));
RUBY_DEBUG_LOG("success target_th:%u status:%s", rb_th_serial(target_th), thread_status_name(target_th, TRUE));
if (target_th->ec->errinfo != Qnil) {
VALUE err = target_th->ec->errinfo;
@ -1198,8 +1109,7 @@ thread_join(rb_thread_t *target_th, VALUE timeout, rb_hrtime_t *limit)
if (FIXNUM_P(err)) {
switch (err) {
case INT2FIX(TAG_FATAL):
thread_debug("thread_join: terminated (thid: %"PRI_THREAD_ID", status: %s)\n",
thread_id_str(target_th), thread_status_name(target_th, TRUE));
RUBY_DEBUG_LOG("terminated target_th:%u status:%s", rb_th_serial(target_th), thread_status_name(target_th, TRUE));
/* OK. killed. */
break;
@ -1384,9 +1294,9 @@ hrtime_update_expire(rb_hrtime_t *timeout, const rb_hrtime_t end)
rb_hrtime_t now = rb_hrtime_now();
if (now > end) return 1;
thread_debug("hrtime_update_expire: "
"%"PRIu64" > %"PRIu64"\n",
(uint64_t)end, (uint64_t)now);
RUBY_DEBUG_LOG("%"PRIu64" > %"PRIu64"", (uint64_t)end, (uint64_t)now);
*timeout = end - now;
return 0;
}
@ -1417,14 +1327,14 @@ sleep_hrtime(rb_thread_t *th, rb_hrtime_t rel, unsigned int fl)
void
rb_thread_sleep_forever(void)
{
thread_debug("rb_thread_sleep_forever\n");
RUBY_DEBUG_LOG("%s", "");
sleep_forever(GET_THREAD(), SLEEP_SPURIOUS_CHECK);
}
void
rb_thread_sleep_deadly(void)
{
thread_debug("rb_thread_sleep_deadly\n");
RUBY_DEBUG_LOG("%s", "");
sleep_forever(GET_THREAD(), SLEEP_DEADLOCKABLE|SLEEP_SPURIOUS_CHECK);
}
@ -1448,7 +1358,7 @@ rb_thread_sleep_deadly_allow_spurious_wakeup(VALUE blocker)
rb_fiber_scheduler_block(scheduler, blocker, Qnil);
}
else {
thread_debug("rb_thread_sleep_deadly_allow_spurious_wakeup\n");
RUBY_DEBUG_LOG("%s", "");
sleep_forever(GET_THREAD(), SLEEP_DEADLOCKABLE);
}
}
@ -1500,16 +1410,18 @@ rb_thread_sleep(int sec)
static void
rb_thread_schedule_limits(uint32_t limits_us)
{
thread_debug("rb_thread_schedule\n");
if (!rb_thread_alone()) {
rb_thread_t *th = GET_THREAD();
RUBY_DEBUG_LOG("us:%u", (unsigned int)limits_us);
if (th->running_time_us >= limits_us) {
thread_debug("rb_thread_schedule/switch start\n");
RB_GC_SAVE_MACHINE_CONTEXT(th);
RUBY_DEBUG_LOG("switch %s", "start");
RB_GC_SAVE_MACHINE_CONTEXT(th);
thread_sched_yield(TH_SCHED(th), th);
rb_ractor_thread_switch(th->ractor, th);
thread_debug("rb_thread_schedule/switch done\n");
RUBY_DEBUG_LOG("switch %s", "done");
}
}
}
@ -1530,14 +1442,17 @@ blocking_region_begin(rb_thread_t *th, struct rb_blocking_region_buffer *region,
#ifdef RUBY_VM_CRITICAL_SECTION
VM_ASSERT(ruby_assert_critical_section_entered == 0);
#endif
VM_ASSERT(th == GET_THREAD());
region->prev_status = th->status;
if (unblock_function_set(th, ubf, arg, fail_if_interrupted)) {
th->blocking_region_buffer = region;
th->status = THREAD_STOPPED;
rb_ractor_blocking_threads_inc(th->ractor, __FILE__, __LINE__);
thread_debug("enter blocking region (%p)\n", (void *)th);
RB_GC_SAVE_MACHINE_CONTEXT(th);
RUBY_DEBUG_LOG("%s", "");
RB_GC_SAVE_MACHINE_CONTEXT(th);
thread_sched_to_waiting(TH_SCHED(th));
return TRUE;
}
@ -1557,12 +1472,14 @@ blocking_region_end(rb_thread_t *th, struct rb_blocking_region_buffer *region)
thread_sched_to_running(TH_SCHED(th), th);
rb_ractor_thread_switch(th->ractor, th);
thread_debug("leave blocking region (%p)\n", (void *)th);
th->blocking_region_buffer = 0;
rb_ractor_blocking_threads_dec(th->ractor, __FILE__, __LINE__);
if (th->status == THREAD_STOPPED) {
th->status = region->prev_status;
}
RUBY_DEBUG_LOG("%s", "");
VM_ASSERT(th == GET_THREAD());
}
void *
@ -2368,7 +2285,7 @@ rb_threadptr_execute_interrupts(rb_thread_t *th, int blocking_timing)
/* exception from another thread */
if (pending_interrupt && threadptr_pending_interrupt_active_p(th)) {
VALUE err = rb_threadptr_pending_interrupt_deque(th, blocking_timing ? INTERRUPT_ON_BLOCKING : INTERRUPT_NONE);
thread_debug("rb_thread_execute_interrupts: %"PRIdVALUE"\n", err);
RUBY_DEBUG_LOG("err:%"PRIdVALUE"\n", err);
ret = TRUE;
if (err == Qundef) {
@ -2589,35 +2506,36 @@ thread_raise_m(int argc, VALUE *argv, VALUE self)
VALUE
rb_thread_kill(VALUE thread)
{
rb_thread_t *th = rb_thread_ptr(thread);
rb_thread_t *target_th = rb_thread_ptr(thread);
if (th->to_kill || th->status == THREAD_KILLED) {
if (target_th->to_kill || target_th->status == THREAD_KILLED) {
return thread;
}
if (th == th->vm->ractor.main_thread) {
if (target_th == target_th->vm->ractor.main_thread) {
rb_exit(EXIT_SUCCESS);
}
thread_debug("rb_thread_kill: %p (%"PRI_THREAD_ID")\n", (void *)th, thread_id_str(th));
RUBY_DEBUG_LOG("target_th:%u", rb_th_serial(target_th));
if (th == GET_THREAD()) {
if (target_th == GET_THREAD()) {
/* kill myself immediately */
rb_threadptr_to_kill(th);
rb_threadptr_to_kill(target_th);
}
else {
threadptr_check_pending_interrupt_queue(th);
rb_threadptr_pending_interrupt_enque(th, eKillSignal);
rb_threadptr_interrupt(th);
threadptr_check_pending_interrupt_queue(target_th);
rb_threadptr_pending_interrupt_enque(target_th, eKillSignal);
rb_threadptr_interrupt(target_th);
}
return thread;
}
int
rb_thread_to_be_killed(VALUE thread)
{
rb_thread_t *th = rb_thread_ptr(thread);
rb_thread_t *target_th = rb_thread_ptr(thread);
if (th->to_kill || th->status == THREAD_KILLED) {
if (target_th->to_kill || target_th->status == THREAD_KILLED) {
return TRUE;
}
return FALSE;
@ -5340,10 +5258,6 @@ Init_Thread(void)
rb_define_singleton_method(rb_cThread, "report_on_exception=", rb_thread_s_report_exc_set, 1);
rb_define_singleton_method(rb_cThread, "ignore_deadlock", rb_thread_s_ignore_deadlock, 0);
rb_define_singleton_method(rb_cThread, "ignore_deadlock=", rb_thread_s_ignore_deadlock_set, 1);
#if THREAD_DEBUG < 0
rb_define_singleton_method(rb_cThread, "DEBUG", rb_thread_s_debug, 0);
rb_define_singleton_method(rb_cThread, "DEBUG=", rb_thread_s_debug_set, 1);
#endif
rb_define_singleton_method(rb_cThread, "handle_interrupt", rb_thread_s_handle_interrupt, 1);
rb_define_singleton_method(rb_cThread, "pending_interrupt?", rb_thread_s_pending_interrupt_p, -1);
rb_define_method(rb_cThread, "pending_interrupt?", rb_thread_pending_interrupt_p, -1);
@ -5429,6 +5343,12 @@ ruby_native_thread_p(void)
return th != 0;
}
#ifdef NON_SCALAR_THREAD_ID
#define thread_id_str(th) (NULL)
#else
#define thread_id_str(th) ((void *)(uintptr_t)(th)->nt->thread_id)
#endif
static void
debug_deadlock_check(rb_ractor_t *r, VALUE msg)
{
@ -5441,7 +5361,7 @@ debug_deadlock_check(rb_ractor_t *r, VALUE msg)
ccan_list_for_each(&r->threads.set, th, lt_node) {
rb_str_catf(msg, "* %+"PRIsVALUE"\n rb_thread_t:%p "
"native:%"PRI_THREAD_ID" int:%u",
"native:%p int:%u",
th->self, (void *)th, thread_id_str(th), th->ec->interrupt_flag);
if (th->locking_mutex) {

View file

@ -1212,7 +1212,7 @@ native_thread_create(rb_thread_t *th)
th->nt = ZALLOC(struct rb_native_thread);
if (use_cached_thread(th)) {
thread_debug("create (use cached thread): %p\n", (void *)th);
RUBY_DEBUG_LOG("use cached nt. th:%u", rb_th_serial(th));
}
else {
pthread_attr_t attr;
@ -1227,8 +1227,8 @@ native_thread_create(rb_thread_t *th)
CHECK_ERR(pthread_attr_init(&attr));
# ifdef PTHREAD_STACK_MIN
thread_debug("create - stack size: %lu\n", (unsigned long)stack_size);
CHECK_ERR(pthread_attr_setstacksize(&attr, stack_size));
RUBY_DEBUG_LOG("stack size: %lu", (unsigned long)stack_size);
CHECK_ERR(pthread_attr_setstacksize(&attr, stack_size));
# endif
# ifdef HAVE_PTHREAD_ATTR_SETINHERITSCHED
@ -1237,8 +1237,10 @@ native_thread_create(rb_thread_t *th)
CHECK_ERR(pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED));
err = pthread_create(&th->nt->thread_id, &attr, thread_start_func_1, th);
thread_debug("create: %p (%d)\n", (void *)th, err);
/* should be done in the created thread */
RUBY_DEBUG_LOG("th:%u err:%d", rb_th_serial(th), err);
/* should be done in the created thread */
CHECK_ERR(pthread_attr_destroy(&attr));
}
return err;
@ -1284,7 +1286,7 @@ static void
ubf_pthread_cond_signal(void *ptr)
{
rb_thread_t *th = (rb_thread_t *)ptr;
thread_debug("ubf_pthread_cond_signal (%p)\n", (void *)th);
RUBY_DEBUG_LOG("th:%u", rb_th_serial(th));
rb_native_cond_signal(&th->nt->cond.intr);
}
@ -1312,7 +1314,7 @@ native_cond_sleep(rb_thread_t *th, rb_hrtime_t *rel)
if (RUBY_VM_INTERRUPTED(th->ec)) {
/* interrupted. return immediate */
thread_debug("native_sleep: interrupted before sleep\n");
RUBY_DEBUG_LOG("interrupted before sleep th:%u", rb_th_serial(th));
}
else {
if (!rel) {
@ -1335,7 +1337,7 @@ native_cond_sleep(rb_thread_t *th, rb_hrtime_t *rel)
}
THREAD_BLOCKING_END(th);
thread_debug("native_sleep done\n");
RUBY_DEBUG_LOG("done th:%u", rb_th_serial(th));
}
#ifdef USE_UBF_LIST
@ -1388,7 +1390,7 @@ unregister_ubf_list(rb_thread_t *th)
static void
ubf_wakeup_thread(rb_thread_t *th)
{
thread_debug("thread_wait_queue_wakeup (%"PRI_THREAD_ID")\n", thread_id_str(th));
RUBY_DEBUG_LOG("th:%u", rb_th_serial(th));
pthread_kill(th->nt->thread_id, SIGVTALRM);
}
@ -2152,7 +2154,7 @@ rb_sigwait_sleep(rb_thread_t *th, int sigwait_fd, const rb_hrtime_t *rel)
check_signals_nogvl(th, sigwait_fd);
}
else {
rb_hrtime_t to = RB_HRTIME_MAX, end;
rb_hrtime_t to = RB_HRTIME_MAX, end = 0;
int n = 0;
if (rel) {

View file

@ -59,31 +59,45 @@ w32_error(const char *func)
UNREACHABLE;
}
#define W32_EVENT_DEBUG 0
#if W32_EVENT_DEBUG
#define w32_event_debug printf
#else
#define w32_event_debug if (0) printf
#endif
static int
w32_mutex_lock(HANDLE lock, bool try)
{
DWORD result;
while (1) {
thread_debug("rb_native_mutex_lock: %p\n", lock);
// RUBY_DEBUG_LOG() is not available because RUBY_DEBUG_LOG() calls it.
w32_event_debug("lock:%p\n", lock);
result = w32_wait_events(&lock, 1, try ? 0 : INFINITE, 0);
switch (result) {
case WAIT_OBJECT_0:
/* get mutex object */
thread_debug("acquire mutex: %p\n", lock);
w32_event_debug("locked lock:%p\n", lock);
return 0;
case WAIT_OBJECT_0 + 1:
case WAIT_OBJECT_0 + 1:
/* interrupt */
errno = EINTR;
thread_debug("acquire mutex interrupted: %p\n", lock);
w32_event_debug("interrupted lock:%p\n", lock);
return 0;
case WAIT_TIMEOUT:
thread_debug("timeout mutex: %p\n", lock);
case WAIT_TIMEOUT:
w32_event_debug("timeout locK:%p\n", lock);
return EBUSY;
case WAIT_ABANDONED:
case WAIT_ABANDONED:
rb_bug("win32_mutex_lock: WAIT_ABANDONED");
break;
default:
rb_bug("win32_mutex_lock: unknown result (%ld)", result);
default:
rb_bug("win32_mutex_lock: unknown result (%ld)", result);
break;
}
}
@ -174,10 +188,10 @@ Init_native_thread(rb_thread_t *main_th)
GetCurrentProcess(),
&main_th->nt->thread_id, 0, FALSE, DUPLICATE_SAME_ACCESS);
thread_debug("initial thread (th: %p, thid: %p, event: %p)\n",
main_th,
main_th->nt->thread_id,
main_th->nt->interrupt_event);
RUBY_DEBUG_LOG("initial thread th:%u thid:%p, event: %p",
rb_th_serial(main_th),
main_th->nt->thread_id,
main_th->nt->interrupt_event);
}
static int
@ -188,34 +202,34 @@ w32_wait_events(HANDLE *events, int count, DWORD timeout, rb_thread_t *th)
const int initcount = count;
DWORD ret;
thread_debug(" w32_wait_events events:%p, count:%d, timeout:%ld, th:%p\n",
events, count, timeout, th);
w32_event_debug("events:%p, count:%d, timeout:%ld, th:%u\n",
events, count, timeout, th ? rb_th_serial(th) : -1);
if (th && (intr = th->nt->interrupt_event)) {
if (ResetEvent(intr) && (!RUBY_VM_INTERRUPTED(th->ec) || SetEvent(intr))) {
targets = ALLOCA_N(HANDLE, count + 1);
memcpy(targets, events, sizeof(HANDLE) * count);
targets[count++] = intr;
thread_debug(" * handle: %p (count: %d, intr)\n", intr, count);
}
w32_event_debug("handle:%p (count:%d, intr)\n", intr, count);
}
else if (intr == th->nt->interrupt_event) {
w32_error("w32_wait_events");
}
}
thread_debug(" WaitForMultipleObjects start (count: %d)\n", count);
w32_event_debug("WaitForMultipleObjects start count:%d\n", count);
ret = WaitForMultipleObjects(count, targets, FALSE, timeout);
thread_debug(" WaitForMultipleObjects end (ret: %lu)\n", ret);
w32_event_debug("WaitForMultipleObjects end ret:%lu\n", ret);
if (ret == (DWORD)(WAIT_OBJECT_0 + initcount) && th) {
errno = EINTR;
}
if (ret == WAIT_FAILED && THREAD_DEBUG) {
if (ret == WAIT_FAILED && W32_EVENT_DEBUG) {
int i;
DWORD dmy;
for (i = 0; i < count; i++) {
thread_debug(" * error handle %d - %s\n", i,
GetHandleInformation(targets[i], &dmy) ? "OK" : "NG");
DWORD dmy;
for (i = 0; i < count; i++) {
w32_event_debug("i:%d %s\n", i, GetHandleInformation(targets[i], &dmy) ? "OK" : "NG");
}
}
return ret;
@ -320,9 +334,9 @@ native_sleep(rb_thread_t *th, rb_hrtime_t *rel)
/* interrupted. return immediate */
}
else {
thread_debug("native_sleep start (%lu)\n", msec);
RUBY_DEBUG_LOG("start msec:%lu", msec);
ret = w32_wait_events(0, 0, msec, th);
thread_debug("native_sleep done (%lu)\n", ret);
RUBY_DEBUG_LOG("done ret:%lu", ret);
}
rb_native_mutex_lock(&th->interrupt_lock);
@ -357,7 +371,7 @@ void
rb_native_mutex_unlock(rb_nativethread_lock_t *lock)
{
#ifdef USE_WIN32_MUTEX
thread_debug("release mutex: %p\n", lock->mutex);
RUBY_DEBUG_LOG("lock:%p", lock->mutex);
ReleaseMutex(lock->mutex);
#else
LeaveCriticalSection(&lock->crit);
@ -597,7 +611,7 @@ static void
native_thread_destroy(rb_thread_t *th)
{
HANDLE intr = InterlockedExchangePointer(&th->nt->interrupt_event, 0);
thread_debug("close handle - intr: %p, thid: %p\n", intr, th->nt->thread_id);
RUBY_DEBUG_LOG("close handle intr:%p, thid:%p\n", intr, th->nt->thread_id);
w32_close_handle(intr);
}
@ -611,13 +625,13 @@ thread_start_func_1(void *th_ptr)
th->nt->interrupt_event = CreateEvent(0, TRUE, FALSE, 0);
/* run */
thread_debug("thread created (th: %p, thid: %p, event: %p)\n", th,
th->nt->thread_id, th->nt->interrupt_event);
RUBY_DEBUG_LOG("thread created th:%u, thid: %p, event: %p",
rb_th_serial(th), th->nt->thread_id, th->nt->interrupt_event);
thread_start_func_2(th, th->ec->machine.stack_start);
w32_close_handle(thread_id);
thread_debug("thread deleted (th: %p)\n", th);
RUBY_DEBUG_LOG("thread deleted th:%u", rb_th_serial(th));
return 0;
}
@ -634,11 +648,11 @@ native_thread_create(rb_thread_t *th)
w32_resume_thread(th->nt->thread_id);
if (THREAD_DEBUG) {
Sleep(0);
thread_debug("create: (th: %p, thid: %p, intr: %p), stack size: %"PRIuSIZE"\n",
th, th->nt->thread_id,
th->nt->interrupt_event, stack_size);
if (USE_RUBY_DEBUG_LOG) {
Sleep(0);
RUBY_DEBUG_LOG("th:%u thid:%p intr:%p), stack size: %"PRIuSIZE"",
rb_th_serial(th), th->nt->thread_id,
th->nt->interrupt_event, stack_size);
}
return 0;
}
@ -702,7 +716,7 @@ static void
ubf_handle(void *ptr)
{
rb_thread_t *th = (rb_thread_t *)ptr;
thread_debug("ubf_handle: %p\n", th);
RUBY_DEBUG_LOG("th:%u\n", rb_th_serial(th));
if (!SetEvent(th->nt->interrupt_event)) {
w32_error("ubf_handle");
@ -723,7 +737,7 @@ static unsigned long __stdcall
timer_thread_func(void *dummy)
{
rb_vm_t *vm = GET_VM();
thread_debug("timer_thread\n");
RUBY_DEBUG_LOG("%s", "start");
rb_w32_set_thread_description(GetCurrentThread(), L"ruby-timer-thread");
while (WaitForSingleObject(timer_thread.lock,
TIME_QUANTUM_USEC/1000) == WAIT_TIMEOUT) {
@ -731,7 +745,7 @@ timer_thread_func(void *dummy)
ruby_sigchld_handler(vm); /* probably no-op */
rb_threadptr_check_signal(vm->ractor.main_thread);
}
thread_debug("timer killed\n");
RUBY_DEBUG_LOG("%s", "end");
return 0;
}
@ -754,8 +768,8 @@ rb_thread_create_timer_thread(void)
if (!timer_thread.lock) {
timer_thread.lock = CreateEvent(0, TRUE, FALSE, 0);
}
timer_thread.id = w32_create_thread(1024 + (THREAD_DEBUG ? BUFSIZ : 0),
timer_thread_func, 0);
timer_thread.id = w32_create_thread(1024 + (USE_RUBY_DEBUG_LOG ? BUFSIZ : 0),
timer_thread_func, 0);
w32_resume_thread(timer_thread.id);
}
}