suppress built-in functions in stack traces

Experiment with removing built-in Racket functions in stack traces to
make the trace less noisy. "Built-in" is defined as code that exists
in the built-in modules. On CS, built-in code is detected as residing
in the static generation. (Also, on CS, the code must have a name but
no source location or detailed debugging information to be
suppressed.) On BC, a code object has a bit set if it's loaded at boot
time.

This change makes stack traces look more like Racket BC traces before
the macro expander was implemented in Racket. The frames for built-in
functions have been useful for implementing the expander and Racket
CS, but probably they're just noise for most users most of the time.

Set the `PLT_SHOW_BUILTIN_CONTEXT` environment variable to preserve
all available frames in the stack trace.
This commit is contained in:
Matthew Flatt 2020-08-28 12:04:35 -06:00
parent 95812bd7a5
commit 0ae3ef7b42
8 changed files with 57 additions and 36 deletions

View File

@ -16,6 +16,8 @@ void scheme_set_allow_set_undefined(int v) { scheme_allow_set_undefined = v; }
int scheme_get_allow_set_undefined() { return scheme_allow_set_undefined; }
THREAD_LOCAL_DECL(int scheme_starting_up);
int scheme_keep_builtin_context;
/* globals READ-ONLY SHARED */
READ_ONLY static Scheme_Object *kernel_symbol;
@ -178,7 +180,7 @@ Scheme_Env *scheme_basic_env()
scheme_init_hash_key_procs();
#endif
scheme_init_getenv(); /* checks PLTNOJIT */
scheme_init_getenv(); /* checks PLTNOJIT and PLT_SHOW_BUILTIN_CONTEXT */
#ifdef WINDOWS_PROCESSES
/* Must be called before first scheme_make_thread() */

View File

@ -20,7 +20,6 @@ static int lambda_has_been_jitted(Scheme_Native_Lambda *nlam);
void scheme_jit_fill_threadlocal_table();
typedef struct {
Scheme_Native_Lambda nc;
Scheme_Native_Lambda *case_lam;
@ -4029,7 +4028,8 @@ static void on_demand_generate_lambda(Scheme_Native_Closure *nc, Scheme_Native_L
start_code = gdata.start_code;
tail_code = gdata.tail_code;
if (lam->name) {
if (lam->name && (scheme_keep_builtin_context
|| ((SCHEME_LAMBDA_FLAGS(lam) & LAMBDA_STATUS_MASK) != LAMBDA_STATUS_BUILTIN))) {
scheme_jit_add_symbol((uintptr_t)jit_unadjust_ip(start_code),
(uintptr_t)jit_unadjust_ip(gdata.code_end) - 1,
lam->name, 1);

View File

@ -210,6 +210,7 @@ Scheme_Object *scheme_read_lambda(int flags, int closure_size, int num_params, i
data = (Scheme_Lambda *)scheme_malloc_tagged(sizeof(Scheme_Lambda));
data->iso.so.type = scheme_lambda_type;
if (scheme_starting_up) flags |= LAMBDA_STATUS_BUILTIN;
SCHEME_LAMBDA_FLAGS(data) = (short)flags;
data->num_params = num_params;

View File

@ -4265,7 +4265,7 @@ static Scheme_Object *finish_optimize_application(Scheme_App_Rec *app, Optimize_
rator_flags = get_rator_flags(rator, app->num_args, info);
info->preserves_marks = !!(rator_flags & LAMBDA_PRESERVES_MARKS);
info->single_result = !!(rator_flags & LAMBDA_SINGLE_RESULT);
if (rator_flags & LAMBDA_RESULT_TENTATIVE) {
if ((rator_flags & LAMBDA_STATUS_MASK) == LAMBDA_STATUS_RESULT_TENTATIVE) {
info->preserves_marks = -info->preserves_marks;
info->single_result = -info->single_result;
}
@ -4790,7 +4790,7 @@ static Scheme_Object *finish_optimize_application2(Scheme_App2_Rec *app, Optimiz
rator_flags = get_rator_flags(rator, 1, info);
info->preserves_marks = !!(rator_flags & LAMBDA_PRESERVES_MARKS);
info->single_result = !!(rator_flags & LAMBDA_SINGLE_RESULT);
if (rator_flags & LAMBDA_RESULT_TENTATIVE) {
if ((rator_flags & LAMBDA_STATUS_MASK) == LAMBDA_STATUS_RESULT_TENTATIVE) {
info->preserves_marks = -info->preserves_marks;
info->single_result = -info->single_result;
}
@ -4946,7 +4946,7 @@ static Scheme_Object *finish_optimize_application3(Scheme_App3_Rec *app, Optimiz
/* Convert to apply-values form: */
return optimize_apply_values(app->rand2, lam->body, info,
((SCHEME_LAMBDA_FLAGS(lam) & LAMBDA_SINGLE_RESULT)
? ((SCHEME_LAMBDA_FLAGS(lam) & LAMBDA_RESULT_TENTATIVE)
? (((SCHEME_LAMBDA_FLAGS(lam) & LAMBDA_STATUS_MASK) == LAMBDA_STATUS_RESULT_TENTATIVE)
? -1
: 1)
: 0),
@ -5298,7 +5298,7 @@ static Scheme_Object *finish_optimize_application3(Scheme_App3_Rec *app, Optimiz
rator_flags = get_rator_flags(app->rator, 2, info);
info->preserves_marks = !!(rator_flags & LAMBDA_PRESERVES_MARKS);
info->single_result = !!(rator_flags & LAMBDA_SINGLE_RESULT);
if (rator_flags & LAMBDA_RESULT_TENTATIVE) {
if ((rator_flags & LAMBDA_STATUS_MASK) == LAMBDA_STATUS_RESULT_TENTATIVE) {
info->preserves_marks = -info->preserves_marks;
info->single_result = -info->single_result;
}
@ -5334,7 +5334,7 @@ Scheme_Object *optimize_apply_values(Scheme_Object *f, Scheme_Object *e,
int flags = SCHEME_LAMBDA_FLAGS(lam);
info->preserves_marks = !!(flags & LAMBDA_PRESERVES_MARKS);
info->single_result = !!(flags & LAMBDA_SINGLE_RESULT);
if (flags & LAMBDA_RESULT_TENTATIVE) {
if ((flags & LAMBDA_STATUS_MASK) == LAMBDA_STATUS_RESULT_TENTATIVE) {
info->preserves_marks = -info->preserves_marks;
info->single_result = -info->single_result;
}
@ -7256,7 +7256,7 @@ static int set_one_code_flags(Scheme_Object *value, int flags,
merge_lambda_arg_types(lam, lam2);
}
if (!just_tentative || (SCHEME_LAMBDA_FLAGS(lam) & LAMBDA_RESULT_TENTATIVE)) {
if (!just_tentative || ((SCHEME_LAMBDA_FLAGS(lam) & LAMBDA_STATUS_MASK) == LAMBDA_STATUS_RESULT_TENTATIVE)) {
flags = (flags & SCHEME_LAMBDA_FLAGS(lam));
SCHEME_LAMBDA_FLAGS(lam2) = set_flags | (SCHEME_LAMBDA_FLAGS(lam2) & mask_flags);
SCHEME_LAMBDA_FLAGS(lam3) = set_flags | (SCHEME_LAMBDA_FLAGS(lam3) & mask_flags);
@ -8070,7 +8070,7 @@ static Scheme_Object *optimize_lets(Scheme_Object *form, Optimize_Info *info, in
/* Set-flags loop: */
clones = make_clones(retry_start, pre_body, rhs_info);
(void)set_code_flags(retry_start, pre_body, clones,
LAMBDA_SINGLE_RESULT | LAMBDA_PRESERVES_MARKS | LAMBDA_RESULT_TENTATIVE,
LAMBDA_SINGLE_RESULT | LAMBDA_PRESERVES_MARKS | LAMBDA_STATUS_RESULT_TENTATIVE,
0xFFFF,
0,
0);
@ -8172,7 +8172,7 @@ static Scheme_Object *optimize_lets(Scheme_Object *form, Optimize_Info *info, in
/* Reset-flags loop: */
(void)set_code_flags(retry_start, pre_body, clones,
(flags & (LAMBDA_SINGLE_RESULT | LAMBDA_PRESERVES_MARKS)),
~(LAMBDA_SINGLE_RESULT | LAMBDA_PRESERVES_MARKS | LAMBDA_RESULT_TENTATIVE),
~(LAMBDA_SINGLE_RESULT | LAMBDA_PRESERVES_MARKS | LAMBDA_STATUS_MASK),
1,
1);
}
@ -8579,8 +8579,8 @@ optimize_lambda(Scheme_Object *_lam, Optimize_Info *info, int context)
SCHEME_LAMBDA_FLAGS(lam) -= LAMBDA_PRESERVES_MARKS;
if ((info->single_result > 0) && (info->preserves_marks > 0)
&& (SCHEME_LAMBDA_FLAGS(lam) & LAMBDA_RESULT_TENTATIVE))
SCHEME_LAMBDA_FLAGS(lam) -= LAMBDA_RESULT_TENTATIVE;
&& ((SCHEME_LAMBDA_FLAGS(lam) & LAMBDA_STATUS_MASK) == LAMBDA_STATUS_RESULT_TENTATIVE))
SCHEME_LAMBDA_FLAGS(lam) -= LAMBDA_STATUS_RESULT_TENTATIVE;
lam->body = code;
@ -9352,7 +9352,7 @@ Scheme_Linklet *scheme_optimize_linklet(Scheme_Linklet *linklet,
LAMBDA_PRESERVES_MARKS for all, but then assume not for all
if any turn out not (i.e., approximate fix point). */
(void)set_code_closure_flags(cl_first,
LAMBDA_SINGLE_RESULT | LAMBDA_PRESERVES_MARKS | LAMBDA_RESULT_TENTATIVE,
LAMBDA_SINGLE_RESULT | LAMBDA_PRESERVES_MARKS | LAMBDA_STATUS_RESULT_TENTATIVE,
0xFFFF,
0);
@ -9430,7 +9430,7 @@ Scheme_Linklet *scheme_optimize_linklet(Scheme_Linklet *linklet,
flags = set_code_closure_flags(cl_first, 0, 0xFFFF, 0);
(void)set_code_closure_flags(cl_first,
(flags & (LAMBDA_SINGLE_RESULT | LAMBDA_PRESERVES_MARKS)),
~(LAMBDA_SINGLE_RESULT | LAMBDA_PRESERVES_MARKS | LAMBDA_RESULT_TENTATIVE),
~(LAMBDA_SINGLE_RESULT | LAMBDA_PRESERVES_MARKS | LAMBDA_STATUS_MASK),
1);
}

View File

@ -501,6 +501,8 @@ Scheme_Object *scheme_get_startup_export(const char *s);
extern int scheme_init_load_on_demand;
extern int scheme_keep_builtin_context;
/*========================================================================*/
/* constants */
/*========================================================================*/
@ -2708,11 +2710,16 @@ Scheme_Comp_Env *scheme_set_comp_env_name(Scheme_Comp_Env *env, Scheme_Object *n
#define LAMBDA_NEED_REST_CLEAR 8
#define LAMBDA_IS_METHOD 16
#define LAMBDA_SINGLE_RESULT 32
#define LAMBDA_RESULT_TENTATIVE 64
#define LAMBDA_VALIDATED 128
#define LAMBDA_STATUS_MASK (64 | 128)
#define LAMBDA_SFS 256
/* BITS 8-15 (overlaps LAMBDA_SFS) used by write_lambda() */
/* These modes correspond to different times for a given `lambda`,
assuming that builtin functions are not validated: */
#define LAMBDA_STATUS_RESULT_TENTATIVE 64
#define LAMBDA_STATUS_VALIDATED 128
#define LAMBDA_STATUS_BUILTIN (128 | 64)
#define COMP_ALLOW_SET_UNDEFINED 0x1
#define COMP_CAN_INLINE 0x2
#define COMP_ENFORCE_CONSTS 0x4

View File

@ -2101,6 +2101,9 @@ void scheme_init_getenv(void)
if (sch_bool_getenv("PLTNOMZJIT")) {
scheme_set_startup_use_jit(0);
}
if (sch_bool_getenv("PLT_SHOW_BUILTIN_CONTEXT")) {
scheme_keep_builtin_context = 1;
}
}
static int sch_bool_getenv(const char* name)

View File

@ -1839,10 +1839,10 @@ static int validate_expr(Mz_CPort *port, Scheme_Object *expr,
no_typed(need_local_type, port);
expr = (Scheme_Object *)SCHEME_CLOSURE_CODE(expr);
data = (Scheme_Lambda *)expr;
if (SCHEME_LAMBDA_FLAGS(data) & LAMBDA_VALIDATED) {
if ((SCHEME_LAMBDA_FLAGS(data) & LAMBDA_STATUS_MASK) == LAMBDA_STATUS_VALIDATED) {
/* Done with this one. */
} else {
SCHEME_LAMBDA_FLAGS(data) |= LAMBDA_VALIDATED;
SCHEME_LAMBDA_FLAGS(data) = (SCHEME_LAMBDA_FLAGS(data) & ~LAMBDA_STATUS_MASK) | LAMBDA_STATUS_VALIDATED;
did_one = 0;
goto top;
}

View File

@ -534,6 +534,10 @@
;; uses even more memory.
(define trace-length-limit 65535)
(define suppress-generation-in-trace (if (getenv "PLT_SHOW_BUILTIN_CONTEXT")
-1
255))
;; Convert a continuation to a list of function-name and
;; source information. Cache the result half-way up the
;; traversal, so that it's amortized constant time.
@ -553,17 +557,18 @@
(let* ([name (or (and (not offset)
(let ([attachments (continuation-next-attachments k)])
(and (pair? attachments)
(not (eq? attachments (continuation-next-attachments (#%$continuation-link k))))
(not (fx= attachments (continuation-next-attachments (#%$continuation-link k))))
(let ([n (extract-mark-from-frame (car attachments) linklet-instantiate-key #f)])
(and n
(string->symbol (format "body of ~a" n)))))))
(let* ([c (if offset
(let ([c (if offset
(#%$continuation-stack-return-code k offset)
(#%$continuation-return-code k))]
[n (#%$code-name c)])
(#%$continuation-return-code k))])
(and (not (eq? (#%$generation c) suppress-generation-in-trace))
(let ([n (#%$code-name c)])
(if (path-or-empty-procedure-name-string? n)
#f
n)))]
n)))))]
[desc
(let* ([ci (#%$code-info (if offset
(#%$continuation-stack-return-code k offset)
@ -683,13 +688,16 @@
(when (or (continuation-condition? v)
(and (exn? v)
(not (exn:fail:user? v))))
(let ([n (|#%app| error-print-context-length)])
(unless (zero? n)
(eprintf "\n context...:")
(let loop ([l (traces->context
(let* ([n (|#%app| error-print-context-length)]
[l (if (zero? n)
'()
(traces->context
(if (exn? v)
(continuation-mark-set-traces (exn-continuation-marks v))
(list (continuation->trace (condition-continuation v)))))]
(list (continuation->trace (condition-continuation v))))))])
(unless (null? l)
(eprintf "\n context...:")
(let loop ([l l]
[prev #f]
[repeats 0]
[n n])