Merge pull request #17457 from muxi/alternate-debug-counters

Add more counters to debug the timer crash on iOS
pull/17459/head
Muxi Yan 6 years ago committed by GitHub
commit 6f675abe85
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
  1. 100
      src/core/lib/gpr/sync_posix.cc
  2. 13
      src/core/lib/iomgr/exec_ctx.cc
  3. 6
      src/core/lib/iomgr/timer_manager.cc

@ -30,11 +30,18 @@
// For debug of the timer manager crash only.
// TODO (mxyan): remove after bug is fixed.
#ifdef GRPC_DEBUG_TIMER_MANAGER
#include <string.h>
void (*g_grpc_debug_timer_manager_stats)(
int64_t timer_manager_init_count, int64_t timer_manager_shutdown_count,
int64_t fork_count, int64_t timer_wait_err, int64_t timer_cv_value,
int64_t timer_mu_value, int64_t abstime_sec_value,
int64_t abstime_nsec_value) = nullptr;
int64_t abstime_nsec_value, int64_t abs_deadline_sec_value,
int64_t abs_deadline_nsec_value, int64_t now1_sec_value,
int64_t now1_nsec_value, int64_t now2_sec_value, int64_t now2_nsec_value,
int64_t add_result_sec_value, int64_t add_result_nsec_value,
int64_t sub_result_sec_value, int64_t sub_result_nsec_value,
int64_t next_value, int64_t start_time_sec,
int64_t start_time_nsec) = nullptr;
int64_t g_timer_manager_init_count = 0;
int64_t g_timer_manager_shutdown_count = 0;
int64_t g_fork_count = 0;
@ -43,6 +50,19 @@ int64_t g_timer_cv_value = 0;
int64_t g_timer_mu_value = 0;
int64_t g_abstime_sec_value = -1;
int64_t g_abstime_nsec_value = -1;
int64_t g_abs_deadline_sec_value = -1;
int64_t g_abs_deadline_nsec_value = -1;
int64_t g_now1_sec_value = -1;
int64_t g_now1_nsec_value = -1;
int64_t g_now2_sec_value = -1;
int64_t g_now2_nsec_value = -1;
int64_t g_add_result_sec_value = -1;
int64_t g_add_result_nsec_value = -1;
int64_t g_sub_result_sec_value = -1;
int64_t g_sub_result_nsec_value = -1;
int64_t g_next_value = -1;
int64_t g_start_time_sec = -1;
int64_t g_start_time_nsec = -1;
#endif // GRPC_DEBUG_TIMER_MANAGER
#ifdef GPR_LOW_LEVEL_COUNTERS
@ -90,17 +110,74 @@ void gpr_cv_init(gpr_cv* cv) {
void gpr_cv_destroy(gpr_cv* cv) { GPR_ASSERT(pthread_cond_destroy(cv) == 0); }
// For debug of the timer manager crash only.
// TODO (mxyan): remove after bug is fixed.
#ifdef GRPC_DEBUG_TIMER_MANAGER
static gpr_timespec gpr_convert_clock_type_debug_timespec(
gpr_timespec t, gpr_clock_type clock_type, gpr_timespec& now1,
gpr_timespec& now2, gpr_timespec& add_result, gpr_timespec& sub_result) {
if (t.clock_type == clock_type) {
return t;
}
if (t.tv_sec == INT64_MAX || t.tv_sec == INT64_MIN) {
t.clock_type = clock_type;
return t;
}
if (clock_type == GPR_TIMESPAN) {
return gpr_time_sub(t, gpr_now(t.clock_type));
}
if (t.clock_type == GPR_TIMESPAN) {
return gpr_time_add(gpr_now(clock_type), t);
}
now1 = gpr_now(t.clock_type);
sub_result = gpr_time_sub(t, now1);
now2 = gpr_now(clock_type);
add_result = gpr_time_add(now2, sub_result);
return add_result;
}
#define gpr_convert_clock_type_debug(t, clock_type, now1, now2, add_result, \
sub_result) \
gpr_convert_clock_type_debug_timespec((t), (clock_type), (now1), (now2), \
(add_result), (sub_result))
#else
#define gpr_convert_clock_type_debug(t, clock_type, now1, now2, add_result, \
sub_result) \
gpr_convert_clock_type((t), (clock_type))
#endif
int gpr_cv_wait(gpr_cv* cv, gpr_mu* mu, gpr_timespec abs_deadline) {
int err = 0;
#ifdef GRPC_DEBUG_TIMER_MANAGER
// For debug of the timer manager crash only.
// TODO (mxyan): remove after bug is fixed.
gpr_timespec abs_deadline_copy;
abs_deadline_copy.tv_sec = abs_deadline.tv_sec;
abs_deadline_copy.tv_nsec = abs_deadline.tv_nsec;
gpr_timespec now1;
gpr_timespec now2;
gpr_timespec add_result;
gpr_timespec sub_result;
memset(&now1, 0, sizeof(now1));
memset(&now2, 0, sizeof(now2));
memset(&add_result, 0, sizeof(add_result));
memset(&sub_result, 0, sizeof(sub_result));
#endif
if (gpr_time_cmp(abs_deadline, gpr_inf_future(abs_deadline.clock_type)) ==
0) {
err = pthread_cond_wait(cv, mu);
} else {
struct timespec abs_deadline_ts;
#if GPR_LINUX
abs_deadline = gpr_convert_clock_type(abs_deadline, GPR_CLOCK_MONOTONIC);
abs_deadline = gpr_convert_clock_type_debug(
abs_deadline, GPR_CLOCK_MONOTONIC, now1, now2, add_result, sub_result);
#else
abs_deadline = gpr_convert_clock_type(abs_deadline, GPR_CLOCK_REALTIME);
abs_deadline = gpr_convert_clock_type_debug(
abs_deadline, GPR_CLOCK_REALTIME, now1, now2, add_result, sub_result);
#endif // GPR_LINUX
abs_deadline_ts.tv_sec = static_cast<time_t>(abs_deadline.tv_sec);
abs_deadline_ts.tv_nsec = abs_deadline.tv_nsec;
@ -123,10 +200,25 @@ int gpr_cv_wait(gpr_cv* cv, gpr_mu* mu, gpr_timespec abs_deadline) {
g_timer_wait_err = err;
g_timer_cv_value = (int64_t)cv;
g_timer_mu_value = (int64_t)mu;
g_abs_deadline_sec_value = abs_deadline_copy.tv_sec;
g_abs_deadline_nsec_value = abs_deadline_copy.tv_nsec;
g_now1_sec_value = now1.tv_sec;
g_now1_nsec_value = now1.tv_nsec;
g_now2_sec_value = now2.tv_sec;
g_now2_nsec_value = now2.tv_nsec;
g_add_result_sec_value = add_result.tv_sec;
g_add_result_nsec_value = add_result.tv_nsec;
g_sub_result_sec_value = sub_result.tv_sec;
g_sub_result_nsec_value = sub_result.tv_nsec;
g_grpc_debug_timer_manager_stats(
g_timer_manager_init_count, g_timer_manager_shutdown_count,
g_fork_count, g_timer_wait_err, g_timer_cv_value, g_timer_mu_value,
g_abstime_sec_value, g_abstime_nsec_value);
g_abstime_sec_value, g_abstime_nsec_value, g_abs_deadline_sec_value,
g_abs_deadline_nsec_value, g_now1_sec_value, g_now1_nsec_value,
g_now2_sec_value, g_now2_nsec_value, g_add_result_sec_value,
g_add_result_nsec_value, g_sub_result_sec_value,
g_sub_result_nsec_value, g_next_value, g_start_time_sec,
g_start_time_nsec);
}
}
#endif

@ -53,6 +53,13 @@ static void exec_ctx_sched(grpc_closure* closure, grpc_error* error) {
static gpr_timespec g_start_time;
// For debug of the timer manager crash only.
// TODO (mxyan): remove after bug is fixed.
#ifdef GRPC_DEBUG_TIMER_MANAGER
extern int64_t g_start_time_sec;
extern int64_t g_start_time_nsec;
#endif // GRPC_DEBUG_TIMER_MANAGER
static grpc_millis timespec_to_millis_round_down(gpr_timespec ts) {
ts = gpr_time_sub(ts, g_start_time);
double x = GPR_MS_PER_SEC * static_cast<double>(ts.tv_sec) +
@ -117,6 +124,12 @@ void ExecCtx::TestOnlyGlobalInit(gpr_timespec new_val) {
void ExecCtx::GlobalInit(void) {
g_start_time = gpr_now(GPR_CLOCK_MONOTONIC);
// For debug of the timer manager crash only.
// TODO (mxyan): remove after bug is fixed.
#ifdef GRPC_DEBUG_TIMER_MANAGER
g_start_time_sec = g_start_time.tv_sec;
g_start_time_nsec = g_start_time.tv_nsec;
#endif
gpr_tls_init(&exec_ctx_);
}

@ -67,6 +67,7 @@ static void timer_thread(void* completed_thread_ptr);
extern int64_t g_timer_manager_init_count;
extern int64_t g_timer_manager_shutdown_count;
extern int64_t g_fork_count;
extern int64_t g_next_value;
#endif // GRPC_DEBUG_TIMER_MANAGER
static void gc_completed_threads(void) {
@ -193,6 +194,11 @@ static bool wait_until(grpc_millis next) {
gpr_log(GPR_INFO, "sleep until kicked");
}
// For debug of the timer manager crash only.
// TODO (mxyan): remove after bug is fixed.
#ifdef GRPC_DEBUG_TIMER_MANAGER
g_next_value = next;
#endif
gpr_cv_wait(&g_cv_wait, &g_mu,
grpc_millis_to_timespec(next, GPR_CLOCK_MONOTONIC));

Loading…
Cancel
Save