diff --git a/src/mzscheme/src/eval.c b/src/mzscheme/src/eval.c index a67fb259fa..08725e0da4 100644 --- a/src/mzscheme/src/eval.c +++ b/src/mzscheme/src/eval.c @@ -7860,13 +7860,7 @@ scheme_do_eval(Scheme_Object *obj, int num_rands, Scheme_Object **rands, f = prim->prim_val; - #ifdef FUTURES_ENABLED - LOG_PRIM_START(f); - #endif v = f(num_rands, rands, (Scheme_Object *)prim); - #ifdef FUTURES_ENABLED - LOG_PRIM_END(f); - #endif DEBUG_CHECK_TYPE(v); } else if (type == scheme_closure_type) { diff --git a/src/mzscheme/src/future.c b/src/mzscheme/src/future.c index b10d589a2c..c6f8734664 100644 --- a/src/mzscheme/src/future.c +++ b/src/mzscheme/src/future.c @@ -468,43 +468,31 @@ void scheme_future_gc_pause() /* Primitive implementations */ /**********************************************************************/ -static long start_ms = 0; - Scheme_Object *start_primitive_tracking(int argc, Scheme_Object *argv[]) { - //Get the start time - struct timeval now; - long ms; - gettimeofday(&now, NULL); - - start_ms = now.tv_usec / 1000.0; - g_print_prims = 1; - printf("Primitive tracking started at "); - print_ms_and_us(); - printf("\n"); return scheme_void; } Scheme_Object *end_primitive_tracking(int argc, Scheme_Object *argv[]) { g_print_prims = 0; - printf("Primitive tracking ended at "); - print_ms_and_us(); - printf("\n"); return scheme_void; } -void print_ms_and_us() +void scheme_log_future_to_runtime(const char *who, void *p) +/* Called in future thread */ { - struct timeval now; - long ms, us; - gettimeofday(&now, NULL); + START_XFORM_SKIP; - //ms = (now.tv_sec * 1000.0) - start_ms; - ms = (now.tv_usec / 1000) - start_ms; - us = now.tv_usec - (ms * 1000) - (start_ms * 1000); - printf("%ld.%ld", ms, us); + if (g_print_prims) { + if (p) + fprintf(stderr, "%p at %lf\n", p, scheme_get_inexact_milliseconds()); + else + fprintf(stderr, "%s at %lf\n", who, scheme_get_inexact_milliseconds()); + } + + END_XFORM_SKIP; } Scheme_Object *future(int argc, Scheme_Object *argv[]) diff --git a/src/mzscheme/src/future.h b/src/mzscheme/src/future.h index 2db66dfc7a..c0d7994a09 100644 --- a/src/mzscheme/src/future.h +++ b/src/mzscheme/src/future.h @@ -119,33 +119,12 @@ extern void clear_futures(void); #endif //Primitive instrumentation stuff -extern int g_print_prims; -extern void print_ms_and_us(void); -#define LOG_PRIM_START(p) \ - if (g_print_prims) \ - { \ - printf("%p ", p); \ - print_ms_and_us(); \ - printf("\n"); \ - } -#define LOG_PRIM_END(p) -/* -#define LOG_PRIM_END(p) \ - if (g_print_prims) \ - { \ - print_ms_and_us(); \ - printf("\n"); \ - } -*/ - -#define LOG_PRIM_W_NAME(name) \ - if (g_print_prims) \ - { \ - printf("%s ", name); \ - print_ms_and_us(); \ - printf("\n"); \ - } +extern void scheme_log_future_to_runtime(const char *who, void *addr); +#define LOG_PRIM_START(p) scheme_log_future_to_runtime(# p, NULL) +#define LOG_PRIM_END(p) /* empty */ +#define LOG_PRIM_W_NAME(name) scheme_log_future_to_runtime(name, NULL) +#define LOG_PRIM_W_ADDR(addr) scheme_log_future_to_runtime(NULL, addr) //Signature flags for primitive invocations //Here the convention is SIG_[arg1type]_[arg2type]..._[return type] diff --git a/src/mzscheme/src/gen-jit-ts.ss b/src/mzscheme/src/gen-jit-ts.ss index e7413ce057..e8b102bc98 100644 --- a/src/mzscheme/src/gen-jit-ts.ss +++ b/src/mzscheme/src/gen-jit-ts.ss @@ -43,10 +43,10 @@ static @|result-type| ts_ ## id(@|args|) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ @|return| scheme_rtcall_@|t|(id, @(string-join arg-names ", ")); \ - else \ + } else \ @|return| id(@(string-join arg-names ", ")); \ END_XFORM_SKIP; \ }}) diff --git a/src/mzscheme/src/jit.c b/src/mzscheme/src/jit.c index 413b4e8db7..d61b91d4cc 100644 --- a/src/mzscheme/src/jit.c +++ b/src/mzscheme/src/jit.c @@ -2168,11 +2168,12 @@ static Scheme_Object *noncm_prim_indirect(Scheme_Prim proc, int argc) { START_XFORM_SKIP; - if (scheme_use_rtcall) + if (scheme_use_rtcall) { + LOG_PRIM_W_ADDR(proc); return scheme_rtcall_iS_s(proc, argc, MZ_RUNSTACK); - else + } else return proc(argc, MZ_RUNSTACK); END_XFORM_SKIP; @@ -2181,9 +2182,10 @@ static Scheme_Object *prim_indirect(Scheme_Primitive_Closure_Proc proc, int argc { START_XFORM_SKIP; - if (scheme_use_rtcall) + if (scheme_use_rtcall) { + LOG_PRIM_W_ADDR(proc); return scheme_rtcall_iSs_s(proc, argc, MZ_RUNSTACK, self); - else + } else return proc(argc, MZ_RUNSTACK, self); END_XFORM_SKIP; @@ -2196,9 +2198,10 @@ static Scheme_Object *prim_indirect(Scheme_Primitive_Closure_Proc proc, int argc static void ts_on_demand(void) { START_XFORM_SKIP; - if (scheme_use_rtcall) + if (scheme_use_rtcall) { + LOG_PRIM_START(on_demand); rtcall_void_void_3args(on_demand_with_args); - else + } else on_demand(); END_XFORM_SKIP; } @@ -2208,9 +2211,9 @@ static void *ts_prepare_retry_alloc(void *p, void *p2) { START_XFORM_SKIP; void *ret; - LOG_PRIM_START(&prepare_retry_alloc); if (scheme_use_rtcall) { + LOG_PRIM_START(prepare_retry_alloc); jit_future_storage[0] = p; jit_future_storage[1] = p2; ret = rtcall_alloc_void_pvoid(GC_make_jit_nursery_page); diff --git a/src/mzscheme/src/jit_ts_def.c b/src/mzscheme/src/jit_ts_def.c index 838dadf60d..d606a61223 100644 --- a/src/mzscheme/src/jit_ts_def.c +++ b/src/mzscheme/src/jit_ts_def.c @@ -2,10 +2,10 @@ static Scheme_Object* ts_ ## id(Scheme_Object* g7, int g8, Scheme_Object** g9) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ return scheme_rtcall_siS_s(id, g7, g8, g9); \ - else \ + } else \ return id(g7, g8, g9); \ END_XFORM_SKIP; \ } @@ -13,10 +13,10 @@ static Scheme_Object* ts_ ## id(Scheme_Object* g7, int g8, Scheme_Object** g9) \ static Scheme_Object* ts_ ## id(int g10, Scheme_Object** g11, Scheme_Object* g12) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ return scheme_rtcall_iSs_s(id, g10, g11, g12); \ - else \ + } else \ return id(g10, g11, g12); \ END_XFORM_SKIP; \ } @@ -24,10 +24,10 @@ static Scheme_Object* ts_ ## id(int g10, Scheme_Object** g11, Scheme_Object* g12 static Scheme_Object* ts_ ## id(Scheme_Object* g13) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ return scheme_rtcall_s_s(id, g13); \ - else \ + } else \ return id(g13); \ END_XFORM_SKIP; \ } @@ -35,10 +35,10 @@ static Scheme_Object* ts_ ## id(Scheme_Object* g13) \ static Scheme_Object* ts_ ## id(Scheme_Native_Closure_Data* g14) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ return scheme_rtcall_n_s(id, g14); \ - else \ + } else \ return id(g14); \ END_XFORM_SKIP; \ } @@ -46,10 +46,10 @@ static Scheme_Object* ts_ ## id(Scheme_Native_Closure_Data* g14) \ static Scheme_Object* ts_ ## id() \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ return scheme_rtcall__s(id, ); \ - else \ + } else \ return id(); \ END_XFORM_SKIP; \ } @@ -57,10 +57,10 @@ static Scheme_Object* ts_ ## id() \ static Scheme_Object* ts_ ## id(Scheme_Object* g15, Scheme_Object* g16) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ return scheme_rtcall_ss_s(id, g15, g16); \ - else \ + } else \ return id(g15, g16); \ END_XFORM_SKIP; \ } @@ -68,10 +68,10 @@ static Scheme_Object* ts_ ## id(Scheme_Object* g15, Scheme_Object* g16) \ static MZ_MARK_STACK_TYPE ts_ ## id(Scheme_Object* g17, Scheme_Object* g18) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ return scheme_rtcall_ss_m(id, g17, g18); \ - else \ + } else \ return id(g17, g18); \ END_XFORM_SKIP; \ } @@ -79,10 +79,10 @@ static MZ_MARK_STACK_TYPE ts_ ## id(Scheme_Object* g17, Scheme_Object* g18) \ static Scheme_Object* ts_ ## id(Scheme_Object** g19, long g20) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ return scheme_rtcall_Sl_s(id, g19, g20); \ - else \ + } else \ return id(g19, g20); \ END_XFORM_SKIP; \ } @@ -90,10 +90,10 @@ static Scheme_Object* ts_ ## id(Scheme_Object** g19, long g20) \ static Scheme_Object* ts_ ## id(long g21) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ return scheme_rtcall_l_s(id, g21); \ - else \ + } else \ return id(g21); \ END_XFORM_SKIP; \ } @@ -101,10 +101,10 @@ static Scheme_Object* ts_ ## id(long g21) \ static void ts_ ## id(Scheme_Bucket* g22, Scheme_Object* g23, int g24) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ scheme_rtcall_bsi_v(id, g22, g23, g24); \ - else \ + } else \ id(g22, g23, g24); \ END_XFORM_SKIP; \ } @@ -112,10 +112,10 @@ static void ts_ ## id(Scheme_Bucket* g22, Scheme_Object* g23, int g24) \ static void ts_ ## id(int g25, int g26, Scheme_Object** g27) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ scheme_rtcall_iiS_v(id, g25, g26, g27); \ - else \ + } else \ id(g25, g26, g27); \ END_XFORM_SKIP; \ } @@ -123,10 +123,10 @@ static void ts_ ## id(int g25, int g26, Scheme_Object** g27) \ static void ts_ ## id(Scheme_Object* g28, Scheme_Object* g29) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ scheme_rtcall_ss_v(id, g28, g29); \ - else \ + } else \ id(g28, g29); \ END_XFORM_SKIP; \ } @@ -134,10 +134,10 @@ static void ts_ ## id(Scheme_Object* g28, Scheme_Object* g29) \ static void ts_ ## id(Scheme_Bucket* g30) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ scheme_rtcall_b_v(id, g30); \ - else \ + } else \ id(g30); \ END_XFORM_SKIP; \ } @@ -145,10 +145,10 @@ static void ts_ ## id(Scheme_Bucket* g30) \ static Scheme_Object* ts_ ## id(Scheme_Object* g31, long g32) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ return scheme_rtcall_sl_s(id, g31, g32); \ - else \ + } else \ return id(g31, g32); \ END_XFORM_SKIP; \ } @@ -156,10 +156,10 @@ static Scheme_Object* ts_ ## id(Scheme_Object* g31, long g32) \ static Scheme_Object* ts_ ## id(int g33, Scheme_Object** g34) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ return scheme_rtcall_iS_s(id, g33, g34); \ - else \ + } else \ return id(g33, g34); \ END_XFORM_SKIP; \ } @@ -167,10 +167,10 @@ static Scheme_Object* ts_ ## id(int g33, Scheme_Object** g34) \ static Scheme_Object* ts_ ## id(Scheme_Object** g35) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ return scheme_rtcall_S_s(id, g35); \ - else \ + } else \ return id(g35); \ END_XFORM_SKIP; \ } @@ -178,10 +178,10 @@ static Scheme_Object* ts_ ## id(Scheme_Object** g35) \ static void ts_ ## id(Scheme_Object* g36) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ scheme_rtcall_s_v(id, g36); \ - else \ + } else \ id(g36); \ END_XFORM_SKIP; \ } @@ -189,10 +189,10 @@ static void ts_ ## id(Scheme_Object* g36) \ static Scheme_Object* ts_ ## id(int g37, Scheme_Object** g38, int g39) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ return scheme_rtcall_iSi_s(id, g37, g38, g39); \ - else \ + } else \ return id(g37, g38, g39); \ END_XFORM_SKIP; \ } @@ -200,10 +200,10 @@ static Scheme_Object* ts_ ## id(int g37, Scheme_Object** g38, int g39) \ static void ts_ ## id(Scheme_Object* g40, int g41, Scheme_Object** g42) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ scheme_rtcall_siS_v(id, g40, g41, g42); \ - else \ + } else \ id(g40, g41, g42); \ END_XFORM_SKIP; \ } @@ -211,10 +211,10 @@ static void ts_ ## id(Scheme_Object* g40, int g41, Scheme_Object** g42) \ static void* ts_ ## id(size_t g43) \ { \ START_XFORM_SKIP; \ - LOG_PRIM_START(&id); \ - if (scheme_use_rtcall) \ + if (scheme_use_rtcall) { \ + LOG_PRIM_START(id); \ return scheme_rtcall_z_p(id, g43); \ - else \ + } else \ return id(g43); \ END_XFORM_SKIP; \ } diff --git a/src/mzscheme/src/schnapp.inc b/src/mzscheme/src/schnapp.inc index 57f1e38441..c045d7ef66 100644 --- a/src/mzscheme/src/schnapp.inc +++ b/src/mzscheme/src/schnapp.inc @@ -31,13 +31,7 @@ static MZ_INLINE Scheme_Object *PRIM_APPLY_NAME_FAST(Scheme_Object *rator, } f = (Scheme_Primitive_Closure_Proc *)prim->prim_val; - #ifdef FUTURES_ENABLED - LOG_PRIM_START(f); - #endif v = f(argc, argv, (Scheme_Object *)prim); - #ifdef FUTURES_ENABLED - LOG_PRIM_END(f); - #endif #if PRIM_CHECK_VALUE if (v == SCHEME_TAIL_CALL_WAITING) {