From a7ba7d178a54efc8c3a3ebbbd67844cf963c96fe Mon Sep 17 00:00:00 2001 From: Richard M Kreuter Date: Thu, 10 Apr 2025 20:31:55 -0400 Subject: [PATCH] Write lossage backtraces to stderr rather than stdout So that a backtrace goes to an appropriate OS channel when a script trips a lose() scenario. The LDB command continues to write to stdout. lisp_backtrace() and backtrace_from_fp() retain their existing signatures & write-to-stdout behavior, since people might call them from external debuggers. (But rename log_backtrace_from_fp() to print_backtrace_from_fp(), for similarity with other printing routines in LDB.) --- src/runtime/backtrace.c | 70 ++++++++++++++++++++--------------- src/runtime/gencgc.c | 3 +- src/runtime/interr.c | 5 +-- src/runtime/monitor.c | 3 +- src/runtime/print.h | 1 + tests/runtime-options.test.sh | 36 ++++++++++++++++++ 6 files changed, 81 insertions(+), 37 deletions(-) create mode 100644 tests/runtime-options.test.sh diff --git a/src/runtime/backtrace.c b/src/runtime/backtrace.c index 0d86dfa5e..9d0401683 100644 --- a/src/runtime/backtrace.c +++ b/src/runtime/backtrace.c @@ -338,6 +338,14 @@ print_entry_points (struct code *code, FILE *f) }); } +/* SBCL itself uses print_lisp_backtrace() with one of stdout or + * stderr. This is the old interface, in case people debug with it. */ +void +lisp_backtrace(int nframes) +{ + void print_lisp_backtrace(int frames, FILE *f); + print_lisp_backtrace(nframes, stdout); +} #if !(defined(LISP_FEATURE_X86) || defined(LISP_FEATURE_X86_64)) @@ -475,7 +483,7 @@ int lisp_frame_previous(struct thread *thread, struct call_info *info) } void -lisp_backtrace(int nframes) +print_lisp_backtrace(int nframes, FILE *f) { struct thread *thread = get_sb_vm_thread(); struct call_info info; @@ -491,41 +499,41 @@ lisp_backtrace(int nframes) do { if (!lisp_frame_previous(thread, &info)) { if (info.frame) // 0 is normal termination of the call chain - printf("Bad frame pointer %p [valid range=%p..%p]\n", info.frame, - thread->control_stack_start, thread->control_stack_end); + fprintf(f, "Bad frame pointer %p [valid range=%p..%p]\n", info.frame, + thread->control_stack_start, thread->control_stack_end); break; } - printf("%4d: ", i); + fprintf(f, "%4d: ", i); // Print spaces to keep the alignment nice if (info.interrupted #ifdef reg_LRA || info.lra == NIL #endif ) { - putchar('['); - if (info.interrupted) { footnotes |= 1; putchar('I'); } + putc('[', f); + if (info.interrupted) { footnotes |= 1; putc('I', f); } #ifdef reg_LRA - if (info.lra == NIL) { footnotes |= 2; putchar('*'); } + if (info.lra == NIL) { footnotes |= 2; putc('*', f); } #endif - putchar(']'); - if (!(info.lra == NIL && info.interrupted)) putchar(' '); + putc(']', f); + if (!(info.lra == NIL && info.interrupted)) putc(' ', f); } else { - printf(" "); + fprintf(f, " "); } - printf("%p ", info.frame); + fprintf(f, "%p ", info.frame); void* absolute_pc = 0; if (info.code) { absolute_pc = (char*)info.code + info.pc; - printf("pc=%p {%p+%04x} ", absolute_pc, info.code, (int)info.pc); + fprintf(f, "pc=%p {%p+%04x} ", absolute_pc, info.code, (int)info.pc); } else { absolute_pc = (char*)info.pc; - printf("pc=%p ", absolute_pc); + fprintf(f, "pc=%p ", absolute_pc); } #ifdef reg_LRA // If LRA does not match the PC, print it. This should not happen. if (info.lra != make_lispobj(absolute_pc, OTHER_POINTER_LOWTAG) && info.lra != NIL) - printf("LRA=%p ", (void*)info.lra); + fprintf(f, "LRA=%p ", (void*)info.lra); #endif int fpvalid = (lispobj*)info.frame >= thread->control_stack_start @@ -533,31 +541,31 @@ lisp_backtrace(int nframes) // If the FP is invalid, then quite likely we'd crash trying to find a // compiled-debug-fun because info.code is a wild pointer - if (!fpvalid) { printf(" BAD FRAME\n"); break; } + if (!fpvalid) { fprintf(f, " BAD FRAME\n"); break; } if (info.code) { lispobj name; if (absolute_pc && (name = debug_function_name_from_pc((struct code *)info.code, absolute_pc))) - print_entry_name(barrier_load(&name), stdout); + print_entry_name(barrier_load(&name), f); else // I can't imagine a scenario where we have info.code // but do not have an absolute_pc, or debug-fun can't be found. // Anyway, we can uniquely identify code by serial# now. - printf("{code_serialno=%x}", code_serialno(info.code)); + fprintf(f, "{code_serialno=%x}", code_serialno(info.code)); } - putchar('\n'); + putc('\n', f); } while (++i <= nframes); - if (footnotes) printf("Note: [I] = interrupted" + if (footnotes) fprintf(f, "Note: [I] = interrupted" #ifdef reg_LRA - ", [*] = no LRA" + ", [*] = no LRA" #endif - "\n"); + "\n"); } -#else +#else /* (defined(LISP_FEATURE_X86) || defined(LISP_FEATURE_X86_64)) */ static int altstack_pointer_p(__attribute__((unused)) struct thread* thread, @@ -696,10 +704,12 @@ static void print_backtrace_frame(char *pc, void *fp, int i, FILE *f) { /* This function has been split from lisp_backtrace() to enable Lisp * backtraces from gdb with call backtrace_from_fp(...). Useful for - * example when debugging threading deadlocks. + * example when debugging threading deadlocks. (SBCL internals call + * print_backtrace_from_fp() however, because the right stream to + * write to is context-dependent.) */ void NO_SANITIZE_MEMORY -log_backtrace_from_fp(struct thread* th, void *fp, int nframes, int start, FILE *f) +print_backtrace_from_fp(struct thread* th, void *fp, int nframes, int start, FILE *f) { int i = start; @@ -715,24 +725,24 @@ log_backtrace_from_fp(struct thread* th, void *fp, int nframes, int start, FILE fflush(f); } void backtrace_from_fp(void *fp, int nframes, int start) { - log_backtrace_from_fp(get_sb_vm_thread(), fp, nframes, start, stdout); + print_backtrace_from_fp(get_sb_vm_thread(), fp, nframes, start, stdout); } void print_backtrace_from_context(os_context_t *context, int nframes, FILE* file) { void *fp = (void *)os_context_frame_pointer(context); print_backtrace_frame((void *)os_context_pc(context), fp, 0, file); - log_backtrace_from_fp(get_sb_vm_thread(), fp, nframes - 1, 1, file); + print_backtrace_from_fp(get_sb_vm_thread(), fp, nframes - 1, 1, file); } void -lisp_backtrace(int nframes) +print_lisp_backtrace(int nframes, FILE *f) { struct thread *thread = get_sb_vm_thread(); int free_ici = fixnum_value(read_TLS(FREE_INTERRUPT_CONTEXT_INDEX,thread)); if (free_ici) { os_context_t *context = nth_interrupt_context(free_ici - 1, thread); - print_backtrace_from_context(context, nframes, stdout); + print_backtrace_from_context(context, nframes, f); } else { void *fp; @@ -741,7 +751,7 @@ lisp_backtrace(int nframes) #elif defined (LISP_FEATURE_X86_64) asm("movq %%rbp,%0" : "=g" (fp)); #endif - backtrace_from_fp(fp, nframes, 0); + print_backtrace_from_fp(get_sb_vm_thread(), fp, nframes, 0, f); } } #endif @@ -878,7 +888,7 @@ void libunwind_backtrace(struct thread *th, FILE* f) #else // If you don't have libunwind, this will almost surely not work, // because we can't figure out how to get backwards past a signal frame. - log_backtrace_from_fp(th, (void*)*os_context_fp_addr(context), 100, 0, stderr); + print_backtrace_from_fp(th, (void*)*os_context_fp_addr(context), 100, 0, stderr); #endif bt_suspension_context = 0; if (th != get_sb_vm_thread()) pthread_kill(th->os_thread, SIGXCPU); diff --git a/src/runtime/gencgc.c b/src/runtime/gencgc.c index b55972f7c..211bd8a7d 100644 --- a/src/runtime/gencgc.c +++ b/src/runtime/gencgc.c @@ -4314,8 +4314,7 @@ int gencgc_handle_wp_violation(__attribute__((unused)) void* context, void* faul break; default: if (!ignore_memoryfaults_on_unprotected_pages) { - void lisp_backtrace(int frames); - lisp_backtrace(10); + print_lisp_backtrace(10, stderr); fprintf(stderr, "Fault @ %p, PC=%p, page %"PAGE_INDEX_FMT" (~WP) mark=%#x gc_active=%d\n" " mixed_region=%p:%p\n" diff --git a/src/runtime/interr.c b/src/runtime/interr.c index 9b7450baf..9f7eff672 100644 --- a/src/runtime/interr.c +++ b/src/runtime/interr.c @@ -35,7 +35,6 @@ #include "gc.h" /* the way that we shut down the system on a fatal error */ -void lisp_backtrace(int frames); extern void ldb_monitor(void); static void @@ -47,7 +46,7 @@ default_lossage_handler(void) // This may not be exactly the right condition for determining // whether it might be possible to backtrace, but at least it prevents // lose() from itself losing early in startup. - if (get_sb_vm_thread()) lisp_backtrace(100); + if (get_sb_vm_thread()) print_lisp_backtrace(100, stderr); } exit(1); } @@ -60,7 +59,7 @@ configurable_lossage_handler() if (dyndebug_config.dyndebug_backtrace_when_lost) { fprintf(stderr, "lose: backtrace follows as requested\n"); - lisp_backtrace(100); + print_lisp_backtrace(100, stderr); } if (dyndebug_config.dyndebug_sleep_when_lost) { diff --git a/src/runtime/monitor.c b/src/runtime/monitor.c index 65622c675..9f97c4624 100644 --- a/src/runtime/monitor.c +++ b/src/runtime/monitor.c @@ -887,7 +887,6 @@ static int print_context_cmd(char **ptr, iochannel_t io) static int backtrace_cmd(char **ptr, iochannel_t io) { - void lisp_backtrace(int frames); int n; if (more_p(ptr)) { @@ -896,7 +895,7 @@ static int backtrace_cmd(char **ptr, iochannel_t io) n = 100; fprintf(io->out, "Backtrace:\n"); - lisp_backtrace(n); + print_lisp_backtrace(n, io->out); return 0; } diff --git a/src/runtime/print.h b/src/runtime/print.h index b7d0811aa..0d3d21d91 100644 --- a/src/runtime/print.h +++ b/src/runtime/print.h @@ -25,6 +25,7 @@ extern void print(lispobj obj); extern void print_to_iochan(lispobj obj,iochannel_t); extern void brief_print(lispobj obj, iochannel_t); extern void reset_printer(void); +extern void print_lisp_backtrace(int frames, FILE *f); #include "genesis/vector.h" #include extern void safely_show_lstring(struct vector*, int, FILE*); diff --git a/tests/runtime-options.test.sh b/tests/runtime-options.test.sh new file mode 100644 index 000000000..656f5fcc6 --- /dev/null +++ b/tests/runtime-options.test.sh @@ -0,0 +1,36 @@ +#!/bin/sh + +# tests related to miscellaneous runtime option behavior. + +# This software is part of the SBCL system. See the README file for +# more information. +# +# While most of SBCL is derived from the CMU CL system, the test +# files (like this one) were written from scratch after the fork +# from CMU CL. +# +# This software is in the public domain and is provided with +# absolutely no warranty. See the COPYING and CREDITS files for +# more information. + +. ./subr.sh + +use_test_subdirectory + +tmpout=$TEST_FILESTEM.lisp-out +tmperr=$TEST_FILESTEM.lisp-err + +# Test that under --lose-on-corruption and --disable-ldb, in case of +# corruption, (a) the process exits non-zero, (b) all +# lose-on-corruption diagnostics go to stderr, and (c) not stdout. +run_sbcl --noinform --lose-on-corruption --disable-ldb --eval '(labels ((foo () (list (foo)))) (foo))' >$tmpout 2>$tmperr +# default_lossage_handler() calls exit(1). +check_status_maybe_lose "--script exit after corruption" $? 1 "(ok)" +[ -s $tmperr ] +check_status_maybe_lose "--script corruption lossage to stderr" $? 0 "(ok)" +[ -s $tmpout ] +check_status_maybe_lose "--script corruption lossage not to stdout" $? 1 "(ok)" + +rm -f $tmpout $tmperr + +exit $EXIT_TEST_WIN