suzanne.soy/racket
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

change to future logging

Browse Source 
svn: r16912
This commit is contained in:
Matthew Flatt 2009-11-20 03:22:10 +00:00
parent b064ebfa75
commit 1e98ff1667
7 changed files with 89 additions and 131 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

6
src/mzscheme/src/eval.c
View File

@ -7860,13 +7860,7 @@ scheme_do_eval(Scheme_Object *obj, int num_rands, Scheme_Object **rands,
f = prim->prim_val; f = prim->prim_val;
#ifdef FUTURES_ENABLED
LOG_PRIM_START(f);
#endif
v = f(num_rands, rands, (Scheme_Object *)prim); v = f(num_rands, rands, (Scheme_Object *)prim);
#ifdef FUTURES_ENABLED
LOG_PRIM_END(f);
#endif
DEBUG_CHECK_TYPE(v); DEBUG_CHECK_TYPE(v);
} else if (type == scheme_closure_type) { } else if (type == scheme_closure_type) {

34
src/mzscheme/src/future.c
View File

@ -468,43 +468,31 @@ void scheme_future_gc_pause()
/* Primitive implementations */ /* Primitive implementations */
/**********************************************************************/ /**********************************************************************/
static long start_ms = 0;
Scheme_Object *start_primitive_tracking(int argc, Scheme_Object *argv[]) 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; g_print_prims = 1;
printf("Primitive tracking started at ");
print_ms_and_us();
printf("\n");
return scheme_void; return scheme_void;
} }
Scheme_Object *end_primitive_tracking(int argc, Scheme_Object *argv[]) Scheme_Object *end_primitive_tracking(int argc, Scheme_Object *argv[])
{ {
g_print_prims = 0; g_print_prims = 0;
printf("Primitive tracking ended at ");
print_ms_and_us();
printf("\n");
return scheme_void; 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; START_XFORM_SKIP;
long ms, us;
gettimeofday(&now, NULL);
//ms = (now.tv_sec * 1000.0) - start_ms; if (g_print_prims) {
ms = (now.tv_usec / 1000) - start_ms; if (p)
us = now.tv_usec - (ms * 1000) - (start_ms * 1000); fprintf(stderr, "%p at %lf\n", p, scheme_get_inexact_milliseconds());
printf("%ld.%ld", ms, us); else
fprintf(stderr, "%s at %lf\n", who, scheme_get_inexact_milliseconds());
}
END_XFORM_SKIP;
} }
Scheme_Object *future(int argc, Scheme_Object *argv[]) Scheme_Object *future(int argc, Scheme_Object *argv[])

31
src/mzscheme/src/future.h
View File

@ -119,33 +119,12 @@ extern void clear_futures(void);
#endif #endif
//Primitive instrumentation stuff //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) 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) \ #define LOG_PRIM_END(p) /* empty */
if (g_print_prims) \ #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)
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"); \
}
//Signature flags for primitive invocations //Signature flags for primitive invocations
//Here the convention is SIG_[arg1type]_[arg2type]..._[return type] //Here the convention is SIG_[arg1type]_[arg2type]..._[return type]

6
src/mzscheme/src/gen-jit-ts.ss
View File

@ -43,10 +43,10 @@
static @|result-type| ts_ ## id(@|args|) \ static @|result-type| ts_ ## id(@|args|) \
{ \ { \
START_XFORM_SKIP; \ 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 ", ")); \ @|return| scheme_rtcall_@|t|(id, @(string-join arg-names ", ")); \
else \ } else \
@|return| id(@(string-join arg-names ", ")); \ @|return| id(@(string-join arg-names ", ")); \
END_XFORM_SKIP; \ END_XFORM_SKIP; \
}}) }})

17
src/mzscheme/src/jit.c
View File

@ -2168,11 +2168,12 @@ static Scheme_Object *noncm_prim_indirect(Scheme_Prim proc, int argc)
{ {
START_XFORM_SKIP; START_XFORM_SKIP;
if (scheme_use_rtcall) if (scheme_use_rtcall) {
LOG_PRIM_W_ADDR(proc);
return scheme_rtcall_iS_s(proc, return scheme_rtcall_iS_s(proc,
argc, argc,
MZ_RUNSTACK); MZ_RUNSTACK);
else } else
return proc(argc, MZ_RUNSTACK); return proc(argc, MZ_RUNSTACK);
END_XFORM_SKIP; END_XFORM_SKIP;
@ -2181,9 +2182,10 @@ static Scheme_Object *prim_indirect(Scheme_Primitive_Closure_Proc proc, int argc
{ {
START_XFORM_SKIP; 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); return scheme_rtcall_iSs_s(proc, argc, MZ_RUNSTACK, self);
else } else
return proc(argc, MZ_RUNSTACK, self); return proc(argc, MZ_RUNSTACK, self);
END_XFORM_SKIP; 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) static void ts_on_demand(void)
{ {
START_XFORM_SKIP; START_XFORM_SKIP;
if (scheme_use_rtcall) if (scheme_use_rtcall) {
LOG_PRIM_START(on_demand);
rtcall_void_void_3args(on_demand_with_args); rtcall_void_void_3args(on_demand_with_args);
else } else
on_demand(); on_demand();
END_XFORM_SKIP; END_XFORM_SKIP;
} }
@ -2208,9 +2211,9 @@ static void *ts_prepare_retry_alloc(void *p, void *p2)
{ {
START_XFORM_SKIP; START_XFORM_SKIP;
void *ret; void *ret;
LOG_PRIM_START(&prepare_retry_alloc);
if (scheme_use_rtcall) { if (scheme_use_rtcall) {
LOG_PRIM_START(prepare_retry_alloc);
jit_future_storage[0] = p; jit_future_storage[0] = p;
jit_future_storage[1] = p2; jit_future_storage[1] = p2;
ret = rtcall_alloc_void_pvoid(GC_make_jit_nursery_page); ret = rtcall_alloc_void_pvoid(GC_make_jit_nursery_page);

120
src/mzscheme/src/jit_ts_def.c
View File

@ -2,10 +2,10 @@
static Scheme_Object* ts_ ## id(Scheme_Object* g7, int g8, Scheme_Object** g9) \ static Scheme_Object* ts_ ## id(Scheme_Object* g7, int g8, Scheme_Object** g9) \
{ \ { \
START_XFORM_SKIP; \ 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); \ return scheme_rtcall_siS_s(id, g7, g8, g9); \
else \ } else \
return id(g7, g8, g9); \ return id(g7, g8, g9); \
END_XFORM_SKIP; \ 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) \ static Scheme_Object* ts_ ## id(int g10, Scheme_Object** g11, Scheme_Object* g12) \
{ \ { \
START_XFORM_SKIP; \ 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); \ return scheme_rtcall_iSs_s(id, g10, g11, g12); \
else \ } else \
return id(g10, g11, g12); \ return id(g10, g11, g12); \
END_XFORM_SKIP; \ 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) \ static Scheme_Object* ts_ ## id(Scheme_Object* g13) \
{ \ { \
START_XFORM_SKIP; \ 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); \ return scheme_rtcall_s_s(id, g13); \
else \ } else \
return id(g13); \ return id(g13); \
END_XFORM_SKIP; \ 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) \ static Scheme_Object* ts_ ## id(Scheme_Native_Closure_Data* g14) \
{ \ { \
START_XFORM_SKIP; \ 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); \ return scheme_rtcall_n_s(id, g14); \
else \ } else \
return id(g14); \ return id(g14); \
END_XFORM_SKIP; \ END_XFORM_SKIP; \
} }
@ -46,10 +46,10 @@ static Scheme_Object* ts_ ## id(Scheme_Native_Closure_Data* g14) \
static Scheme_Object* ts_ ## id() \ static Scheme_Object* ts_ ## id() \
{ \ { \
START_XFORM_SKIP; \ START_XFORM_SKIP; \
LOG_PRIM_START(&id); \ if (scheme_use_rtcall) { \
if (scheme_use_rtcall) \ LOG_PRIM_START(id); \
return scheme_rtcall__s(id, ); \ return scheme_rtcall__s(id, ); \
else \ } else \
return id(); \ return id(); \
END_XFORM_SKIP; \ END_XFORM_SKIP; \
} }
@ -57,10 +57,10 @@ static Scheme_Object* ts_ ## id() \
static Scheme_Object* ts_ ## id(Scheme_Object* g15, Scheme_Object* g16) \ static Scheme_Object* ts_ ## id(Scheme_Object* g15, Scheme_Object* g16) \
{ \ { \
START_XFORM_SKIP; \ 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); \ return scheme_rtcall_ss_s(id, g15, g16); \
else \ } else \
return id(g15, g16); \ return id(g15, g16); \
END_XFORM_SKIP; \ 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) \ static MZ_MARK_STACK_TYPE ts_ ## id(Scheme_Object* g17, Scheme_Object* g18) \
{ \ { \
START_XFORM_SKIP; \ 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); \ return scheme_rtcall_ss_m(id, g17, g18); \
else \ } else \
return id(g17, g18); \ return id(g17, g18); \
END_XFORM_SKIP; \ 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) \ static Scheme_Object* ts_ ## id(Scheme_Object** g19, long g20) \
{ \ { \
START_XFORM_SKIP; \ 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); \ return scheme_rtcall_Sl_s(id, g19, g20); \
else \ } else \
return id(g19, g20); \ return id(g19, g20); \
END_XFORM_SKIP; \ END_XFORM_SKIP; \
} }
@ -90,10 +90,10 @@ static Scheme_Object* ts_ ## id(Scheme_Object** g19, long g20) \
static Scheme_Object* ts_ ## id(long g21) \ static Scheme_Object* ts_ ## id(long g21) \
{ \ { \
START_XFORM_SKIP; \ 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); \ return scheme_rtcall_l_s(id, g21); \
else \ } else \
return id(g21); \ return id(g21); \
END_XFORM_SKIP; \ 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) \ static void ts_ ## id(Scheme_Bucket* g22, Scheme_Object* g23, int g24) \
{ \ { \
START_XFORM_SKIP; \ 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); \ scheme_rtcall_bsi_v(id, g22, g23, g24); \
else \ } else \
id(g22, g23, g24); \ id(g22, g23, g24); \
END_XFORM_SKIP; \ 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) \ static void ts_ ## id(int g25, int g26, Scheme_Object** g27) \
{ \ { \
START_XFORM_SKIP; \ 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); \ scheme_rtcall_iiS_v(id, g25, g26, g27); \
else \ } else \
id(g25, g26, g27); \ id(g25, g26, g27); \
END_XFORM_SKIP; \ 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) \ static void ts_ ## id(Scheme_Object* g28, Scheme_Object* g29) \
{ \ { \
START_XFORM_SKIP; \ 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); \ scheme_rtcall_ss_v(id, g28, g29); \
else \ } else \
id(g28, g29); \ id(g28, g29); \
END_XFORM_SKIP; \ END_XFORM_SKIP; \
} }
@ -134,10 +134,10 @@ static void ts_ ## id(Scheme_Object* g28, Scheme_Object* g29) \
static void ts_ ## id(Scheme_Bucket* g30) \ static void ts_ ## id(Scheme_Bucket* g30) \
{ \ { \
START_XFORM_SKIP; \ 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); \ scheme_rtcall_b_v(id, g30); \
else \ } else \
id(g30); \ id(g30); \
END_XFORM_SKIP; \ END_XFORM_SKIP; \
} }
@ -145,10 +145,10 @@ static void ts_ ## id(Scheme_Bucket* g30) \
static Scheme_Object* ts_ ## id(Scheme_Object* g31, long g32) \ static Scheme_Object* ts_ ## id(Scheme_Object* g31, long g32) \
{ \ { \
START_XFORM_SKIP; \ 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); \ return scheme_rtcall_sl_s(id, g31, g32); \
else \ } else \
return id(g31, g32); \ return id(g31, g32); \
END_XFORM_SKIP; \ 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) \ static Scheme_Object* ts_ ## id(int g33, Scheme_Object** g34) \
{ \ { \
START_XFORM_SKIP; \ 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); \ return scheme_rtcall_iS_s(id, g33, g34); \
else \ } else \
return id(g33, g34); \ return id(g33, g34); \
END_XFORM_SKIP; \ 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) \ static Scheme_Object* ts_ ## id(Scheme_Object** g35) \
{ \ { \
START_XFORM_SKIP; \ 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); \ return scheme_rtcall_S_s(id, g35); \
else \ } else \
return id(g35); \ return id(g35); \
END_XFORM_SKIP; \ END_XFORM_SKIP; \
} }
@ -178,10 +178,10 @@ static Scheme_Object* ts_ ## id(Scheme_Object** g35) \
static void ts_ ## id(Scheme_Object* g36) \ static void ts_ ## id(Scheme_Object* g36) \
{ \ { \
START_XFORM_SKIP; \ 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); \ scheme_rtcall_s_v(id, g36); \
else \ } else \
id(g36); \ id(g36); \
END_XFORM_SKIP; \ 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) \ static Scheme_Object* ts_ ## id(int g37, Scheme_Object** g38, int g39) \
{ \ { \
START_XFORM_SKIP; \ 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); \ return scheme_rtcall_iSi_s(id, g37, g38, g39); \
else \ } else \
return id(g37, g38, g39); \ return id(g37, g38, g39); \
END_XFORM_SKIP; \ 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) \ static void ts_ ## id(Scheme_Object* g40, int g41, Scheme_Object** g42) \
{ \ { \
START_XFORM_SKIP; \ 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); \ scheme_rtcall_siS_v(id, g40, g41, g42); \
else \ } else \
id(g40, g41, g42); \ id(g40, g41, g42); \
END_XFORM_SKIP; \ 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) \ static void* ts_ ## id(size_t g43) \
{ \ { \
START_XFORM_SKIP; \ 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); \ return scheme_rtcall_z_p(id, g43); \
else \ } else \
return id(g43); \ return id(g43); \
END_XFORM_SKIP; \ END_XFORM_SKIP; \
} }

6
src/mzscheme/src/schnapp.inc
View File

@ -31,13 +31,7 @@ static MZ_INLINE Scheme_Object *PRIM_APPLY_NAME_FAST(Scheme_Object *rator,
} }
f = (Scheme_Primitive_Closure_Proc *)prim->prim_val; f = (Scheme_Primitive_Closure_Proc *)prim->prim_val;
#ifdef FUTURES_ENABLED
LOG_PRIM_START(f);
#endif
v = f(argc, argv, (Scheme_Object *)prim); v = f(argc, argv, (Scheme_Object *)prim);
#ifdef FUTURES_ENABLED
LOG_PRIM_END(f);
#endif
#if PRIM_CHECK_VALUE #if PRIM_CHECK_VALUE
if (v == SCHEME_TAIL_CALL_WAITING) { if (v == SCHEME_TAIL_CALL_WAITING) {