diff --git a/configure.ac b/configure.ac index 3301b5bf5..c97b8c51c 100644 --- a/configure.ac +++ b/configure.ac @@ -362,6 +362,7 @@ AC_SEARCH_LIBS( pthread_create, pthread, , [AC_MSG_ERROR([Cannot find the pthrea AC_SEARCH_LIBS( setupterm, [ncurses tinfo curses], , [AC_MSG_ERROR([Could not find a curses implementation, needed to build fish. If this is Linux, try running 'sudo apt-get install libncurses5-dev' or 'sudo yum install ncurses-devel'])] ) AC_SEARCH_LIBS( [nan], [m], [AC_DEFINE( [HAVE_NAN], [1], [Define to 1 if you have the nan function])] ) AC_SEARCH_LIBS( [backtrace_symbols_fd], [execinfo] ) +AC_SEARCH_LIBS( [dladdr], [dl] ) if test x$local_gettext != xno; then AC_SEARCH_LIBS( gettext, intl,,) diff --git a/doc_src/fish.txt b/doc_src/fish.txt index bf9c3eb1b..eb4d24baf 100644 --- a/doc_src/fish.txt +++ b/doc_src/fish.txt @@ -25,4 +25,6 @@ The following options are available: - `-v` or `--version` display version and exit +- `-D` or `--debug-stack-frames=DEBUG_LEVEL` specify how many stack frames to display when debug messages are written. The default is zero. A value of 3 or 4 is usually sufficient to gain insight into how a given debug call was reached but you can specify a value up to 128. + The fish exit status is generally the exit status of the last foreground command. If fish is exiting because of a parse error, the exit status is 127. diff --git a/src/common.cpp b/src/common.cpp index 834f7b8b3..aa27c5371 100644 --- a/src/common.cpp +++ b/src/common.cpp @@ -2,6 +2,8 @@ #include "config.h" #include +#include +#include #include #include #include @@ -49,12 +51,16 @@ static bool thread_assertions_configured_for_testing = false; wchar_t ellipsis_char; wchar_t omitted_newline_char; - bool g_profiling_active = false; - const wchar_t *program_name; +int debug_level = 1; // default maximum debug output level (errors and warnings) +int debug_stack_frames = 0; // default number of stack frames to show on debug() calls -int debug_level = 1; +/// This allows us to notice when we've forked. +static pid_t initial_pid = 0; + +/// Be able to restore the term's foreground process group. +static pid_t initial_foreground_process_group = -1; /// This struct maintains the current state of the terminal size. It is updated on demand after /// receiving a SIGWINCH. Do not touch this struct directly, it's managed with a rwlock. Use @@ -65,18 +71,53 @@ static rwlock_t termsize_rwlock; static char *wcs2str_internal(const wchar_t *in, char *out); -void show_stackframe() { +// This function produces a stack backtrace with demangled function & method names. It is based on +// https://gist.github.com/fmela/591333 but adapted to the style of the fish project. +static const wcstring_list_t __attribute__((noinline)) +demangled_backtrace(int max_frames, int skip_levels) { + void *callstack[128]; + const int n_max_frames = sizeof(callstack) / sizeof(callstack[0]); + int n_frames = backtrace(callstack, n_max_frames); + char **symbols = backtrace_symbols(callstack, n_frames); + wchar_t text[1024]; + std::vector backtrace_text; + + if (skip_levels + max_frames < n_frames) n_frames = skip_levels + max_frames; + + for (int i = skip_levels; i < n_frames; i++) { + Dl_info info; + if (dladdr(callstack[i], &info) && info.dli_sname) { + char *demangled = NULL; + int status = -1; + if (info.dli_sname[0] == '_') + demangled = abi::__cxa_demangle(info.dli_sname, NULL, 0, &status); + swprintf(text, sizeof(text) / sizeof(wchar_t), L"%-3d %s + %td", i - skip_levels, + status == 0 ? demangled : info.dli_sname == 0 ? symbols[i] : info.dli_sname, + (char *)callstack[i] - (char *)info.dli_saddr); + free(demangled); + } else { + swprintf(text, sizeof(text) / sizeof(wchar_t), L"%-3d %s", i - skip_levels, symbols[i]); + } + backtrace_text.push_back(text); + } + free(symbols); + return backtrace_text; +} + +static void debug_shared(const wchar_t msg_level, const wcstring &msg); +void __attribute__((noinline)) show_stackframe(const wchar_t msg_level, int frame_count, + int skip_levels) { ASSERT_IS_NOT_FORKED_CHILD(); // Hack to avoid showing backtraces in the tester. if (program_name && !wcscmp(program_name, L"(ignore)")) return; - void *trace[32]; - int trace_size = 0; - - trace_size = backtrace(trace, 32); - debug(0, L"Backtrace:"); - backtrace_symbols_fd(trace, trace_size, STDERR_FILENO); + if (frame_count < 1) frame_count = 999; + debug_shared(msg_level, L"Backtrace:"); + std::vector bt = demangled_backtrace(frame_count, skip_levels + 2); + for (int i = 0; i < bt.size(); i++) { + debug_shared(msg_level, bt[i]); + } } int fgetws2(wcstring *s, FILE *f) { @@ -493,23 +534,34 @@ static bool should_debug(int level) { return true; } -static void debug_shared(const wcstring &msg) { - const wcstring sb = wcstring(program_name) + L": " + msg; - fwprintf(stderr, L"%ls", reformat_for_screen(sb).c_str()); +static void debug_shared(const wchar_t level, const wcstring &msg) { + pid_t current_pid = getpid(); + + if (current_pid == initial_pid) { + fwprintf(stderr, L"<%lc> %ls: %ls\n", (unsigned long)level, program_name, msg.c_str()); + } else { + fwprintf(stderr, L"<%lc> %ls: %d: %ls\n", (unsigned long)level, program_name, current_pid, + msg.c_str()); + } } -void debug(int level, const wchar_t *msg, ...) { +static wchar_t level_char[] = {L'E', L'W', L'2', L'3', L'4', L'5'}; +void __attribute__((noinline)) debug(int level, const wchar_t *msg, ...) { if (!should_debug(level)) return; int errno_old = errno; va_list va; va_start(va, msg); wcstring local_msg = vformat_string(msg, va); va_end(va); - debug_shared(local_msg); + const wchar_t msg_level = level <= 5 ? level_char[level] : L'9'; + debug_shared(msg_level, local_msg); + if (debug_stack_frames > 0) { + show_stackframe(msg_level, debug_stack_frames, 1); + } errno = errno_old; } -void debug(int level, const char *msg, ...) { +void __attribute__((noinline)) debug(int level, const char *msg, ...) { if (!should_debug(level)) return; int errno_old = errno; char local_msg[512]; @@ -517,7 +569,11 @@ void debug(int level, const char *msg, ...) { va_start(va, msg); vsnprintf(local_msg, sizeof local_msg, msg, va); va_end(va); - debug_shared(str2wcstring(local_msg)); + const wchar_t msg_level = level <= 5 ? level_char[level] : L'9'; + debug_shared(msg_level, str2wcstring(local_msg)); + if (debug_stack_frames > 0) { + show_stackframe(msg_level, debug_stack_frames, 1); + } errno = errno_old; } @@ -1470,7 +1526,7 @@ int create_directory(const wcstring &d) { } __attribute__((noinline)) void bugreport() { - debug(1, _(L"This is a bug. Break on bugreport to debug." + debug(1, _(L"This is a bug. Break on bugreport to debug. " L"If you can reproduce it, please send a bug report to %s."), PACKAGE_BUGREPORT); } @@ -1630,12 +1686,6 @@ void configure_thread_assertions_for_testing(void) { thread_assertions_configured_for_testing = true; } -/// Notice when we've forked. -static pid_t initial_pid = 0; - -/// Be able to restore the term's foreground process group. -static pid_t initial_foreground_process_group = -1; - bool is_forked_child(void) { // Just bail if nobody's called setup_fork_guards, e.g. some of our tools. if (!initial_pid) return false; @@ -1712,14 +1762,14 @@ void assert_is_locked(void *vmutex, const char *who, const char *caller) { void scoped_lock::lock(void) { assert(!locked); - assert(!is_forked_child()); + ASSERT_IS_NOT_FORKED_CHILD(); VOMIT_ON_FAILURE_NO_ERRNO(pthread_mutex_lock(lock_obj)); locked = true; } void scoped_lock::unlock(void) { assert(locked); - assert(!is_forked_child()); + ASSERT_IS_NOT_FORKED_CHILD(); VOMIT_ON_FAILURE_NO_ERRNO(pthread_mutex_unlock(lock_obj)); locked = false; } @@ -1736,35 +1786,35 @@ scoped_lock::~scoped_lock() { void scoped_rwlock::lock(void) { assert(!(locked || locked_shared)); - assert(!is_forked_child()); + ASSERT_IS_NOT_FORKED_CHILD(); VOMIT_ON_FAILURE_NO_ERRNO(pthread_rwlock_rdlock(rwlock_obj)); locked = true; } void scoped_rwlock::unlock(void) { assert(locked); - assert(!is_forked_child()); + ASSERT_IS_NOT_FORKED_CHILD(); VOMIT_ON_FAILURE_NO_ERRNO(pthread_rwlock_unlock(rwlock_obj)); locked = false; } void scoped_rwlock::lock_shared(void) { assert(!(locked || locked_shared)); - assert(!is_forked_child()); + ASSERT_IS_NOT_FORKED_CHILD(); VOMIT_ON_FAILURE_NO_ERRNO(pthread_rwlock_wrlock(rwlock_obj)); locked_shared = true; } void scoped_rwlock::unlock_shared(void) { assert(locked_shared); - assert(!is_forked_child()); + ASSERT_IS_NOT_FORKED_CHILD(); VOMIT_ON_FAILURE_NO_ERRNO(pthread_rwlock_unlock(rwlock_obj)); locked_shared = false; } void scoped_rwlock::upgrade(void) { assert(locked_shared); - assert(!is_forked_child()); + ASSERT_IS_NOT_FORKED_CHILD(); VOMIT_ON_FAILURE_NO_ERRNO(pthread_rwlock_unlock(rwlock_obj)); locked = false; VOMIT_ON_FAILURE_NO_ERRNO(pthread_rwlock_wrlock(rwlock_obj)); diff --git a/src/common.h b/src/common.h index 3d1a771f5..ea0805f02 100644 --- a/src/common.h +++ b/src/common.h @@ -175,6 +175,9 @@ extern wchar_t omitted_newline_char; /// it will not be printed. extern int debug_level; +/// How many stack frames to show when a debug() call is made. +extern int debug_stack_frames; + /// Profiling flag. True if commands should be profiled. extern bool g_profiling_active; @@ -192,7 +195,7 @@ void write_ignore(int fd, const void *buff, size_t count); if (!(arg)) { \ debug(0, "function %s called with null value for argument %s. ", __func__, #arg); \ bugreport(); \ - show_stackframe(); \ + show_stackframe(L'E'); \ return retval; \ } @@ -200,7 +203,7 @@ void write_ignore(int fd, const void *buff, size_t count); #define FATAL_EXIT() \ { \ char exit_read_buff; \ - show_stackframe(); \ + show_stackframe(L'E'); \ read_ignore(0, &exit_read_buff, 1); \ exit_without_destructors(1); \ } @@ -219,7 +222,7 @@ void write_ignore(int fd, const void *buff, size_t count); if (signal_is_blocked()) { \ debug(0, "function %s called while blocking signals. ", __func__); \ bugreport(); \ - show_stackframe(); \ + show_stackframe(L'E'); \ return retval; \ } @@ -234,7 +237,7 @@ void write_ignore(int fd, const void *buff, size_t count); #define contains(str, ...) contains_internal(str, 0, __VA_ARGS__, NULL) /// Print a stack trace to stderr. -void show_stackframe(); +void show_stackframe(const wchar_t msg_level, int frame_count = -1, int skip_levels = 0); /// Read a line from the stream f into the string. Returns the number of bytes read or -1 on /// failure. @@ -485,8 +488,6 @@ class null_terminated_array_t { void convert_wide_array_to_narrow(const null_terminated_array_t &arr, null_terminated_array_t *output); -bool is_forked_child(); - class mutex_lock_t { public: pthread_mutex_t mutex; @@ -668,8 +669,8 @@ ssize_t read_loop(int fd, void *buff, size_t count); /// /// will print the string 'fish: Pi = 3.141', given that debug_level is 1 or higher, and that /// program_name is 'fish'. -void debug(int level, const char *msg, ...); -void debug(int level, const wchar_t *msg, ...); +void __attribute__((noinline)) debug(int level, const char *msg, ...); +void __attribute__((noinline)) debug(int level, const wchar_t *msg, ...); /// Replace special characters with backslash escape sequences. Newline is replaced with \n, etc. /// diff --git a/src/exec.cpp b/src/exec.cpp index 63f2cb775..afd09f6aa 100644 --- a/src/exec.cpp +++ b/src/exec.cpp @@ -948,7 +948,7 @@ void exec_job(parser_t &parser, job_t *j) { bool builtin_io_done = do_builtin_io(outbuff.data(), outbuff.size(), errbuff.data(), errbuff.size()); if (!builtin_io_done && errno != EPIPE) { - show_stackframe(); + show_stackframe(L'E'); } fork_was_skipped = true; } diff --git a/src/fish.cpp b/src/fish.cpp index d8192c86d..c4158dde9 100644 --- a/src/fish.cpp +++ b/src/fish.cpp @@ -309,11 +309,12 @@ static int read_init(const struct config_paths_t &paths) { return 1; } -/// Parse the argument list, return the index of the first non-switch arguments. +/// Parse the argument list, return the index of the first non-flag arguments. static int fish_parse_opt(int argc, char **argv, std::vector *cmds) { - const char *short_opts = "+hilnvc:p:d:"; + const char *short_opts = "+hilnvc:p:d:D:"; const struct option long_opts[] = {{"command", required_argument, NULL, 'c'}, {"debug-level", required_argument, NULL, 'd'}, + {"debug-stack-frames", required_argument, NULL, 'D'}, {"interactive", no_argument, NULL, 'i'}, {"login", no_argument, NULL, 'l'}, {"no-execute", no_argument, NULL, 'n'}, @@ -343,7 +344,7 @@ static int fish_parse_opt(int argc, char **argv, std::vector *cmds) if (tmp >= 0 && tmp <= 10 && !*end && !errno) { debug_level = (int)tmp; } else { - fwprintf(stderr, _(L"Invalid value '%s' for debug level switch"), optarg); + fwprintf(stderr, _(L"Invalid value '%s' for debug-level flag"), optarg); exit(1); } break; @@ -373,6 +374,21 @@ static int fish_parse_opt(int argc, char **argv, std::vector *cmds) fwprintf(stdout, _(L"%s, version %s\n"), PACKAGE_NAME, get_fish_version()); exit(0); } + case 'D': { + char *end; + long tmp; + + errno = 0; + tmp = strtol(optarg, &end, 10); + + if (tmp > 0 && tmp <= 128 && !*end && !errno) { + debug_stack_frames = (int)tmp; + } else { + fwprintf(stderr, _(L"Invalid value '%s' for debug-stack-frames flag"), optarg); + exit(1); + } + break; + } default: { // We assume getopt_long() has already emitted a diagnostic msg. exit(1); diff --git a/tests/status.err b/tests/status.err index 91645c95f..b04178e47 100644 --- a/tests/status.err +++ b/tests/status.err @@ -1,2 +1,2 @@ -fish: An error occurred while redirecting file '/' + fish: An error occurred while redirecting file '/' open: Is a directory