From 63a16befd45f33bcaa10dcc53b64abd000cde48f Mon Sep 17 00:00:00 2001 From: ridiculousfish Date: Sat, 20 Apr 2019 00:15:51 -0700 Subject: [PATCH] Introduce the fish log, a replacement for debug() This adds a new mechanism for logging, intended to replace debug(). The entry points are FLOG and FLOGF. FLOG can be used to log a sequence of arguments, FLOGF is for printf-style formatted strings. Each call to FLOG and FLOGF requires a category. If logging for a category is not enabled, there is no effect (and arguments are not evaluated). Categories may be enabled on the command line via the -d option. --- CHANGELOG.md | 1 + CMakeLists.txt | 1 + sphinx_doc_src/cmds/fish.rst | 4 ++ src/fish.cpp | 45 +++++++++++- src/flog.cpp | 94 +++++++++++++++++++++++++ src/flog.h | 133 +++++++++++++++++++++++++++++++++++ 6 files changed, 276 insertions(+), 2 deletions(-) create mode 100644 src/flog.cpp create mode 100644 src/flog.h diff --git a/CHANGELOG.md b/CHANGELOG.md index 1c3c4a870..351b5ab3a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -14,6 +14,7 @@ - `eval` is now implemented internally rather than being a function; as such, the evaluated code now shares the same argument scope as `eval` rather than being executed in a new scope (#4443). - An issue resulting in a certain class of parser errors not resulting in a non-zero `$status` has been corrected (3e055f). - fish now underlines every valid entered path instead of just the last one. +- The `--debug` option has been extended to allow specifying categories. Categories may be listed via `fish --print-debug-categories`. ### Syntax changes and new commands - Brace expansion now only takes place if the braces include a "," or a variable expansion, so things like `git reset HEAD@{0}` now work (#5869). diff --git a/CMakeLists.txt b/CMakeLists.txt index 0179915f9..238046952 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -89,6 +89,7 @@ SET(FISH_SRCS src/signal.cpp src/tinyexpr.cpp src/tnode.cpp src/tokenizer.cpp src/utf8.cpp src/util.cpp src/wcstringutil.cpp src/wgetopt.cpp src/wildcard.cpp src/wutil.cpp src/future_feature_flags.cpp src/redirection.cpp src/topic_monitor.cpp + src/flog.cpp ) # Header files are just globbed. diff --git a/sphinx_doc_src/cmds/fish.rst b/sphinx_doc_src/cmds/fish.rst index 0a11cd531..f3a2dbaca 100644 --- a/sphinx_doc_src/cmds/fish.rst +++ b/sphinx_doc_src/cmds/fish.rst @@ -22,6 +22,8 @@ The following options are available: - ``-d`` or ``--debug-level=DEBUG_LEVEL`` specify the verbosity level of fish. A higher number means higher verbosity. The default level is 1. +- ``-o`` or ``--debug-output=path`` Specify a file path to receive the debug output. The default is stderr. + - ``-i`` or ``--interactive`` specify that fish is to run in interactive mode - ``-l`` or ``--login`` specify that fish is to run as a login shell @@ -32,6 +34,8 @@ The following options are available: - ``--print-rusage-self`` when fish exits, output stats from getrusage +- ``--print-debug-categories`` outputs the list of debug categories, and then exits. + - ``-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. diff --git a/src/fish.cpp b/src/fish.cpp index 2ea6db5ac..7afe73ed9 100644 --- a/src/fish.cpp +++ b/src/fish.cpp @@ -44,6 +44,7 @@ Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA #include "expand.h" #include "fallback.h" // IWYU pragma: keep #include "fish_version.h" +#include "flog.h" #include "function.h" #include "future_feature_flags.h" #include "history.h" @@ -61,6 +62,8 @@ class fish_cmd_opts_t { public: // Future feature flags values string wcstring features; + // File path for debug output. + std::string debug_output; // Commands to be executed in place of interactive shell. std::vector batch_cmds; // Commands to execute after the shell's config has been read. @@ -263,11 +266,13 @@ static int fish_parse_opt(int argc, char **argv, fish_cmd_opts_t *opts) { {"init-command", required_argument, NULL, 'C'}, {"features", required_argument, NULL, 'f'}, {"debug-level", required_argument, NULL, 'd'}, + {"debug-output", required_argument, NULL, 'o'}, {"debug-stack-frames", required_argument, NULL, 'D'}, {"interactive", no_argument, NULL, 'i'}, {"login", no_argument, NULL, 'l'}, {"no-execute", no_argument, NULL, 'n'}, {"print-rusage-self", no_argument, NULL, 1}, + {"print-debug-categories", no_argument, NULL, 2}, {"profile", required_argument, NULL, 'p'}, {"private", no_argument, NULL, 'P'}, {"help", no_argument, NULL, 'h'}, @@ -295,11 +300,14 @@ static int fish_parse_opt(int argc, char **argv, fish_cmd_opts_t *opts) { if (tmp >= 0 && tmp <= 10 && !*end && !errno) { debug_level = (int)tmp; } else { - std::fwprintf(stderr, _(L"Invalid value '%s' for debug-level flag"), optarg); - exit(1); + activate_flog_categories_by_pattern(str2wcstring(optarg)); } break; } + case 'o': { + opts->debug_output = optarg; + break; + } case 'f': { opts->features = str2wcstring(optarg); break; @@ -324,6 +332,22 @@ static int fish_parse_opt(int argc, char **argv, fish_cmd_opts_t *opts) { opts->print_rusage_self = true; break; } + case 2: { + auto cats = get_flog_categories(); + // Compute width of longest name. + int name_width = 0; + for (const auto *cat : cats) { + name_width = std::max(name_width, (int)wcslen(cat->name)); + } + // A little extra space. + name_width += 2; + for (const auto *cat : cats) { + // Negating the name width left-justifies. + printf("%*ls %ls\n", -name_width, cat->name, _(cat->description)); + } + exit(0); + break; + } case 'p': { s_profiling_output_filename = optarg; g_profiling_active = true; @@ -396,6 +420,20 @@ int main(int argc, char **argv) { fish_cmd_opts_t opts{}; my_optind = fish_parse_opt(argc, argv, &opts); + // Direct any debug output right away. + FILE *debug_output = nullptr; + if (!opts.debug_output.empty()) { + debug_output = fopen(opts.debug_output.c_str(), "w"); + if (!debug_output) { + fprintf(stderr, "Could not open file %s\n", opts.debug_output.c_str()); + perror("fopen"); + exit(-1); + } + set_cloexec(fileno(debug_output)); + setlinebuf(debug_output); + set_flog_output_file(debug_output); + } + // No-exec is prohibited when in interactive mode. if (opts.is_interactive_session && opts.no_exec) { debug(1, _(L"Can not use the no-execute mode when running an interactive session")); @@ -501,6 +539,9 @@ int main(int argc, char **argv) { if (opts.print_rusage_self) { print_rusage_self(stderr); } + if (debug_output) { + fclose(debug_output); + } exit_without_destructors(exit_status); return EXIT_FAILURE; // above line should always exit } diff --git a/src/flog.cpp b/src/flog.cpp new file mode 100644 index 000000000..490b78ee5 --- /dev/null +++ b/src/flog.cpp @@ -0,0 +1,94 @@ +// fish logging +#include "config.h" + +#include "flog.h" +#include "global_safety.h" + +#include "common.h" +#include "enum_set.h" +#include "parse_util.h" +#include "wildcard.h" + +#include + +namespace flog_details { + +// Note we are relying on the order of global initialization within this file. +// It is important that 'all' be initialized before 'g_categories', because g_categories wants to +// append to all in the ctor. +/// This is not modified after initialization. +static std::vector s_all_categories; + +/// When a category is instantiated it adds itself to the 'all' list. +category_t::category_t(const wchar_t *name, const wchar_t *desc, bool enabled) + : name(name), description(desc), enabled(enabled) { + s_all_categories.push_back(this); +} + +/// Instantiate all categories. +/// This is deliberately leaked to avoid pointless destructor registration. +category_list_t *const category_list_t::g_instance = new category_list_t(); + +logger_t::logger_t() : file_(stderr) {} + +owning_lock g_logger; + +void logger_t::log1(const wchar_t *s) { std::fputws(s, file_); } +void logger_t::log1(const char *s) { std::fputs(s, file_); } + +void logger_t::log1(wchar_t c) { std::fputwc(c, file_); } +void logger_t::log1(char c) { std::fputc(c, file_); } + +void logger_t::log_fmt(const category_t &cat, const wchar_t *fmt, ...) { + va_list va; + va_start(va, fmt); + log1(cat.name); + log1(": "); + std::vfwprintf(file_, fmt, va); + log1('\n'); + va_end(va); +} + +void logger_t::log_fmt(const category_t &cat, const char *fmt, ...) { + va_list va; + va_start(va, fmt); + log1(cat.name); + log1(": "); + std::vfprintf(file_, fmt, va); + log1('\n'); + va_end(va); +} + +} // namespace flog_details + +using namespace flog_details; + +/// For each category, if its name matches the wildcard, set its enabled to the given sense. +static void apply_one_wildcard(const wcstring &wc_esc, bool sense) { + wcstring wc = parse_util_unescape_wildcards(wc_esc); + for (category_t *cat : s_all_categories) { + if (wildcard_match(cat->name, wc)) { + cat->enabled = sense; + } + } +} + +void activate_flog_categories_by_pattern(const wcstring &wc) { + for (const wcstring &s : split_string(wc, L',')) { + if (string_prefixes_string(s, L"-")) { + apply_one_wildcard(s.substr(1), false); + } else { + apply_one_wildcard(s, true); + } + } +} + +void set_flog_output_file(FILE *f) { g_logger.acquire()->set_file(f); } + +std::vector get_flog_categories() { + std::vector result(s_all_categories.begin(), s_all_categories.end()); + std::sort(result.begin(), result.end(), [](const category_t *a, const category_t *b) { + return wcscmp(a->name, b->name) < 0; + }); + return result; +} diff --git a/src/flog.h b/src/flog.h new file mode 100644 index 000000000..255db39fb --- /dev/null +++ b/src/flog.h @@ -0,0 +1,133 @@ +/// The flogger: debug logging support for fish. +#ifndef FISH_FLOG_H +#define FISH_FLOG_H + +#include "config.h" // IWYU pragma: keep + +#include "global_safety.h" + +#include +#include +#include +#include + +using wcstring = std::wstring; +using wcstring_list_t = std::vector; + +template +class owning_lock; + +namespace flog_details { + +class category_list_t; +class category_t { + friend category_list_t; + category_t(const wchar_t *name, const wchar_t *desc, bool enabled = false); + + public: + /// The name of this category. + const wchar_t *const name; + + /// A (non-localized) description of the category. + const wchar_t *const description; + + /// Whether the category is enabled. + relaxed_atomic_bool_t enabled; +}; + +class category_list_t { + category_list_t() = default; + + public: + /// The singleton global category list instance. + static category_list_t *const g_instance; + + /// What follows are the actual logging categories. + /// To add a new category simply define a new field, following the pattern. + + category_t error{L"error", L"Serious unexpected errors (on by default)", true}; + + category_t debug{L"debug", L"Debugging aid (on by default)", true}; +}; + +/// The class responsible for logging. +/// This is protected by a lock. +class logger_t { + FILE *file_; + + void log1(const wchar_t *); + void log1(const char *); + void log1(wchar_t); + void log1(char); + + void log1(const wcstring &s) { log1(s.c_str()); } + void log1(const std::string &s) { log1(s.c_str()); } + + template ::value>::type> + void log1(const T &v) { + log1(to_string(v)); + } + + template + void log_args_impl(const T &arg) { + log1(arg); + } + + template + void log_args_impl(const T &arg, const Ts &... rest) { + log1(arg); + log1(' '); + log_args_impl(rest...); + } + + public: + void set_file(FILE *f) { file_ = f; } + + logger_t(); + + template + void log_args(const category_t &cat, const Args &... args) { + log1(cat.name); + log1(": "); + log_args_impl(args...); + log1('\n'); + } + + void log_fmt(const category_t &cat, const wchar_t *fmt, ...); + void log_fmt(const category_t &cat, const char *fmt, ...); +}; + +extern owning_lock g_logger; + +} // namespace flog_details + +/// Set the active flog categories according to the given wildcard \p wc. +void activate_flog_categories_by_pattern(const wcstring &wc); + +/// Set the file that flog should output to. +/// flog does not close this file. +void set_flog_output_file(FILE *f); + +/// \return a list of all categories, sorted by name. +std::vector get_flog_categories(); + +/// Output to the fish log a sequence of arguments, separated by spaces, and ending with a newline. +#define FLOG(wht, ...) \ + do { \ + if (flog_details::category_list_t::g_instance->wht.enabled) { \ + flog_details::g_logger.acquire()->log_args( \ + flog_details::category_list_t::g_instance->wht, __VA_ARGS__); \ + } \ + } while (0) + +/// Output to the fish log a printf-style formatted string. +#define FLOGF(wht, ...) \ + do { \ + if (flog_details::category_list_t::g_instance->wht.enabled) { \ + flog_details::g_logger.acquire()->log_fmt( \ + flog_details::category_list_t::g_instance->wht, __VA_ARGS__); \ + } \ + } while (0) + +#endif