From 63a16befd45f33bcaa10dcc53b64abd000cde48f Mon Sep 17 00:00:00 2001 From: ridiculousfish Date: Sat, 20 Apr 2019 00:15:51 -0700 Subject: [PATCH 1/7] 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 From 8774860468a2257129dcd7179896fcc689f3fb5c Mon Sep 17 00:00:00 2001 From: ridiculousfish Date: Sat, 18 May 2019 13:47:27 -0700 Subject: [PATCH 2/7] Convert job logging from debug to FLOG --- src/exec.cpp | 9 +++++---- src/flog.h | 6 ++++++ src/proc.cpp | 6 ++++-- 3 files changed, 15 insertions(+), 6 deletions(-) diff --git a/src/exec.cpp b/src/exec.cpp index 9ccac5cb8..34e4ed438 100644 --- a/src/exec.cpp +++ b/src/exec.cpp @@ -32,6 +32,7 @@ #include "env.h" #include "exec.h" #include "fallback.h" // IWYU pragma: keep +#include "flog.h" #include "function.h" #include "io.h" #include "iothread.h" @@ -639,8 +640,8 @@ static bool handle_builtin_output(parser_t &parser, const std::shared_ptr // TODO: factor this job-status-setting stuff into a single place. p->completed = 1; if (p->is_last_in_job) { - debug(4, L"Set status of job %d (%ls) to %d using short circuit", j->job_id, - j->preview().c_str(), p->status); + FLOGF(exec_job_status, L"Set status of job %d (%ls) to %d using short circuit", + j->job_id, j->preview().c_str(), p->status); parser.set_last_statuses(j->get_statuses()); } return true; @@ -1096,8 +1097,8 @@ bool exec_job(parser_t &parser, shared_ptr j) { } } - debug(3, L"Created job %d from command '%ls' with pgrp %d", j->job_id, j->command_wcstr(), - j->pgid); + FLOG(exec_job_exec, "Executed job", j->job_id, "from command", j->command_wcstr(), "with pgrp", + j->pgid); j->set_flag(job_flag_t::CONSTRUCTED, true); if (!j->is_foreground()) { diff --git a/src/flog.h b/src/flog.h index 255db39fb..6044eafb0 100644 --- a/src/flog.h +++ b/src/flog.h @@ -48,6 +48,12 @@ class category_list_t { 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}; + + category_t exec_job_status{L"exec-job-status", L"Jobs changing status"}; + + category_t exec_job_exec{L"exec-job-exec", L"Jobs being executed"}; + + category_t proc_job_run{L"proc-job-run", L"Jobs getting started or continued"}; }; /// The class responsible for logging. diff --git a/src/proc.cpp b/src/proc.cpp index 9df9fa3fa..a2dae6f32 100644 --- a/src/proc.cpp +++ b/src/proc.cpp @@ -38,6 +38,7 @@ #include "common.h" #include "event.h" #include "fallback.h" // IWYU pragma: keep +#include "flog.h" #include "global_safety.h" #include "io.h" #include "output.h" @@ -842,8 +843,9 @@ void job_t::continue_job(parser_t &parser, bool reclaim_foreground_pgrp, bool se parser.job_promote(this); set_flag(job_flag_t::NOTIFIED, false); - debug(4, L"%ls job %d, gid %d (%ls), %ls, %ls", send_sigcont ? L"Continue" : L"Start", job_id, - pgid, command_wcstr(), is_completed() ? L"COMPLETED" : L"UNCOMPLETED", + FLOGF(proc_job_run, L"%ls job %d, gid %d (%ls), %ls, %ls", + send_sigcont ? L"Continue" : L"Start", job_id, pgid, command_wcstr(), + is_completed() ? L"COMPLETED" : L"UNCOMPLETED", is_interactive ? L"INTERACTIVE" : L"NON-INTERACTIVE"); // Make sure we retake control of the terminal before leaving this function. From d9676bb2a82938e2b5e84d4a208ea7dee7ab7c1f Mon Sep 17 00:00:00 2001 From: ridiculousfish Date: Sat, 18 May 2019 13:49:59 -0700 Subject: [PATCH 3/7] Convert fork events from debug to flog --- src/exec.cpp | 4 ++-- src/flog.h | 3 +++ 2 files changed, 5 insertions(+), 2 deletions(-) diff --git a/src/exec.cpp b/src/exec.cpp index 34e4ed438..ce9b6568a 100644 --- a/src/exec.cpp +++ b/src/exec.cpp @@ -452,7 +452,7 @@ static bool fork_child_for_process(const std::shared_ptr &job, process_t // This is the parent process. Store away information on the child, and // possibly give it control over the terminal. - debug(4, L"Fork #%d, pid %d: %s for '%ls'", g_fork_count, pid, fork_type, p->argv0()); + FLOGF(exec_fork, L"Fork #%d, pid %d: %s for '%ls'", g_fork_count, pid, fork_type, p->argv0()); p->pid = pid; on_process_created(job, p->pid); @@ -715,7 +715,7 @@ static bool exec_external_command(parser_t &parser, const std::shared_ptr // A 0 pid means we failed to posix_spawn. Since we have no pid, we'll never get // told when it's exited, so we have to mark the process as failed. - debug(4, L"Fork #%d, pid %d: spawn external command '%s' from '%ls'", g_fork_count, pid, + FLOGF(exec_fork, L"Fork #%d, pid %d: spawn external command '%s' from '%ls'", g_fork_count, pid, actual_cmd, file ? file : L""); if (pid == 0) { job_mark_process_as_failed(j, p); diff --git a/src/flog.h b/src/flog.h index 6044eafb0..d2efdde8a 100644 --- a/src/flog.h +++ b/src/flog.h @@ -53,7 +53,10 @@ class category_list_t { category_t exec_job_exec{L"exec-job-exec", L"Jobs being executed"}; + category_t exec_fork{L"exec-fork", L"Calls to fork()"}; + category_t proc_job_run{L"proc-job-run", L"Jobs getting started or continued"}; + }; /// The class responsible for logging. From 46a9da83e89e39a6f71f355c9d277a3103779982 Mon Sep 17 00:00:00 2001 From: ridiculousfish Date: Sat, 18 May 2019 14:51:16 -0700 Subject: [PATCH 4/7] Convert terminal ownership logging from debug to flog --- src/flog.h | 1 + src/postfork.cpp | 3 ++- src/proc.cpp | 10 +++++----- 3 files changed, 8 insertions(+), 6 deletions(-) diff --git a/src/flog.h b/src/flog.h index d2efdde8a..4c0d9ad21 100644 --- a/src/flog.h +++ b/src/flog.h @@ -57,6 +57,7 @@ class category_list_t { category_t proc_job_run{L"proc-job-run", L"Jobs getting started or continued"}; + category_t proc_termowner{L"proc-termowner", L"Terminal ownership events"}; }; /// The class responsible for logging. diff --git a/src/postfork.cpp b/src/postfork.cpp index b59e41883..0fbd442cb 100644 --- a/src/postfork.cpp +++ b/src/postfork.cpp @@ -15,6 +15,7 @@ #include "common.h" #include "exec.h" +#include "flog.h" #include "io.h" #include "iothread.h" #include "postfork.h" @@ -143,7 +144,7 @@ bool maybe_assign_terminal(const job_t *j) { // this can cause an EPERM error. In addition, if we've given control of the terminal to // a process group, attempting to call tcsetpgrp from the background will cause SIGTTOU // to be sent to everything in our process group (unless we handle it). - debug(4, L"Process group %d already has control of terminal\n", j->pgid); + FLOGF(proc_termowner, L"Process group %d already has control of terminal", j->pgid); } else { // No need to duplicate the code here, a function already exists that does just this. return terminal_give_to_job(j, false /*new job, so not continuing*/); diff --git a/src/proc.cpp b/src/proc.cpp index a2dae6f32..7ccda9b4d 100644 --- a/src/proc.cpp +++ b/src/proc.cpp @@ -686,7 +686,7 @@ void proc_update_jiffies(parser_t &parser) { // restoring a previously-stopped job, in which case we need to restore terminal attributes. bool terminal_give_to_job(const job_t *j, bool restore_attrs) { if (j->pgid == 0) { - debug(2, "terminal_give_to_job() returning early due to no process group"); + FLOG(proc_termowner, "terminal_give_to_job() returning early due to no process group"); return true; } @@ -701,10 +701,10 @@ bool terminal_give_to_job(const job_t *j, bool restore_attrs) { // to hand over control of the terminal to this process group, which is a no-op if it's already // been done. if (j->pgid == INVALID_PID || tcgetpgrp(STDIN_FILENO) == j->pgid) { - debug(4, L"Process group %d already has control of terminal\n", j->pgid); + FLOGF(proc_termowner, L"Process group %d already has control of terminal", j->pgid); } else { - debug(4, - L"Attempting to bring process group to foreground via tcsetpgrp for job->pgid %d\n", + FLOGF(proc_termowner, + L"Attempting to bring process group to foreground via tcsetpgrp for job->pgid %d", j->pgid); // The tcsetpgrp(2) man page says that EPERM is thrown if "pgrp has a supported value, but @@ -717,7 +717,7 @@ bool terminal_give_to_job(const job_t *j, bool restore_attrs) { // guarantee the process isn't going to exit while we wait (which would cause us to possibly // block indefinitely). while (tcsetpgrp(STDIN_FILENO, j->pgid) != 0) { - debug(3, "tcsetpgrp failed: %d", errno); + FLOGF(proc_termowner, "tcsetpgrp failed: %d", errno); bool pgroup_terminated = false; // No need to test for EINTR as we are blocking signals From 6282ac5713ff2351abab0f217340c6c189ff709e Mon Sep 17 00:00:00 2001 From: ridiculousfish Date: Sat, 18 May 2019 15:16:42 -0700 Subject: [PATCH 5/7] Convert locale variable changes from debug to flog --- src/env_dispatch.cpp | 11 ++++++----- src/flog.h | 2 ++ 2 files changed, 8 insertions(+), 5 deletions(-) diff --git a/src/env_dispatch.cpp b/src/env_dispatch.cpp index c45034a86..c472ae2ad 100644 --- a/src/env_dispatch.cpp +++ b/src/env_dispatch.cpp @@ -38,6 +38,7 @@ #include "env_universal_common.h" #include "event.h" #include "fallback.h" // IWYU pragma: keep +#include "flog.h" #include "function.h" #include "global_safety.h" #include "history.h" @@ -498,22 +499,22 @@ static void init_locale(const environment_t &vars) { const auto var = vars.get(var_name, ENV_EXPORT); const std::string &name = wcs2string(var_name); if (var.missing_or_empty()) { - debug(5, L"locale var %s missing or empty", name.c_str()); + FLOGF(env_locale, L"locale var %s missing or empty", name.c_str()); unsetenv_lock(name.c_str()); } else { const std::string value = wcs2string(var->as_string()); - debug(5, L"locale var %s='%s'", name.c_str(), value.c_str()); + FLOGF(env_locale, L"locale var %s='%s'", name.c_str(), value.c_str()); setenv_lock(name.c_str(), value.c_str(), 1); } } char *locale = setlocale(LC_ALL, ""); fish_setlocale(); - debug(5, L"init_locale() setlocale(): '%s'", locale); + FLOGF(env_locale, L"init_locale() setlocale(): '%s'", locale); const char *new_msg_locale = setlocale(LC_MESSAGES, NULL); - debug(5, L"old LC_MESSAGES locale: '%s'", old_msg_locale); - debug(5, L"new LC_MESSAGES locale: '%s'", new_msg_locale); + FLOGF(env_locale, L"old LC_MESSAGES locale: '%s'", old_msg_locale); + FLOGF(env_locale, L"new LC_MESSAGES locale: '%s'", new_msg_locale); #ifdef HAVE__NL_MSG_CAT_CNTR if (std::strcmp(old_msg_locale, new_msg_locale)) { // Make change known to GNU gettext. diff --git a/src/flog.h b/src/flog.h index 4c0d9ad21..48b5728ba 100644 --- a/src/flog.h +++ b/src/flog.h @@ -58,6 +58,8 @@ class category_list_t { category_t proc_job_run{L"proc-job-run", L"Jobs getting started or continued"}; category_t proc_termowner{L"proc-termowner", L"Terminal ownership events"}; + + category_t env_locale{L"env-locale", L"Changes to locale variables"}; }; /// The class responsible for logging. From ea9d1ad82faf4c60d5d544f4090cc185a2749f06 Mon Sep 17 00:00:00 2001 From: ridiculousfish Date: Mon, 27 May 2019 15:56:53 -0700 Subject: [PATCH 6/7] Convert debug(0) calls to FLOG --- src/builtin.cpp | 3 ++- src/common.cpp | 27 ++++++++++++++------------- src/complete.cpp | 2 +- src/env.cpp | 7 ++++--- src/env_universal_common.cpp | 36 ++++++++++++++++++++---------------- src/exec.cpp | 10 +++++----- src/expand.cpp | 2 +- src/history.cpp | 2 +- src/iothread.cpp | 3 ++- src/output.cpp | 5 +++-- src/parse_constants.h | 2 +- src/parse_execution.cpp | 13 +++++++------ src/parse_productions.cpp | 11 ++++++----- src/parse_tree.cpp | 3 ++- src/path.cpp | 17 +++++++++-------- src/postfork.cpp | 2 +- src/proc.cpp | 12 ++++++------ src/reader.cpp | 5 +++-- src/sanity.cpp | 7 ++++--- src/tokenizer.cpp | 2 +- src/wutil.cpp | 3 ++- 21 files changed, 95 insertions(+), 79 deletions(-) diff --git a/src/builtin.cpp b/src/builtin.cpp index 9aef6e344..9b91f2f12 100644 --- a/src/builtin.cpp +++ b/src/builtin.cpp @@ -66,6 +66,7 @@ #include "complete.h" #include "exec.h" #include "fallback.h" // IWYU pragma: keep +#include "flog.h" #include "intern.h" #include "io.h" #include "parse_constants.h" @@ -469,7 +470,7 @@ proc_status_t builtin_run(parser_t &parser, int job_pgid, wchar_t **argv, io_str return proc_status_t::from_exit_code(ret); } - debug(0, UNKNOWN_BUILTIN_ERR_MSG, argv[0]); + FLOGF(error, UNKNOWN_BUILTIN_ERR_MSG, argv[0]); return proc_status_t::from_exit_code(STATUS_CMD_ERROR); } diff --git a/src/common.cpp b/src/common.cpp index 8e1ad13ab..44091d56a 100644 --- a/src/common.cpp +++ b/src/common.cpp @@ -52,6 +52,7 @@ #include "env.h" #include "expand.h" #include "fallback.h" // IWYU pragma: keep +#include "flog.h" #include "future_feature_flags.h" #include "global_safety.h" #include "proc.h" @@ -2121,8 +2122,8 @@ int create_directory(const wcstring &d) { } [[gnu::noinline]] void bugreport() { - debug(0, _(L"This is a bug. Break on 'bugreport' to debug.")); - debug(0, _(L"If you can reproduce it, please report: %s."), PACKAGE_BUGREPORT); + FLOG(error, _(L"This is a bug. Break on 'bugreport' to debug.")); + FLOG(error, _(L"If you can reproduce it, please report: "), PACKAGE_BUGREPORT, '.'); } wcstring format_size(long long sz) { @@ -2314,24 +2315,24 @@ bool is_main_thread() { void assert_is_main_thread(const char *who) { if (!is_main_thread() && !thread_asserts_cfg_for_testing) { - debug(0, "%s called off of main thread.", who); - debug(0, "Break on debug_thread_error to debug."); + FLOGF(error, "%s called off of main thread.", who); + FLOGF(error, "Break on debug_thread_error to debug."); debug_thread_error(); } } void assert_is_not_forked_child(const char *who) { if (is_forked_child()) { - debug(0, "%s called in a forked child.", who); - debug(0, "Break on debug_thread_error to debug."); + FLOGF(error, "%s called in a forked child.", who); + FLOGF(error, "Break on debug_thread_error to debug."); debug_thread_error(); } } void assert_is_background_thread(const char *who) { if (is_main_thread() && !thread_asserts_cfg_for_testing) { - debug(0, "%s called on the main thread (may block!).", who); - debug(0, "Break on debug_thread_error to debug."); + FLOGF(error, "%s called on the main thread (may block!).", who); + FLOGF(error, "Break on debug_thread_error to debug."); debug_thread_error(); } } @@ -2342,8 +2343,8 @@ void assert_is_locked(void *vmutex, const char *who, const char *caller) { // Note that std::mutex.try_lock() is allowed to return false when the mutex isn't // actually locked; fortunately we are checking the opposite so we're safe. if (mutex->try_lock()) { - debug(0, "%s is not locked when it should be in '%s'", who, caller); - debug(0, "Break on debug_thread_error to debug."); + FLOGF(error, "%s is not locked when it should be in '%s'", who, caller); + FLOGF(error, "Break on debug_thread_error to debug."); debug_thread_error(); mutex->unlock(); } @@ -2436,10 +2437,10 @@ void redirect_tty_output() { /// Display a failed assertion message, dump a stack trace if possible, then die. [[noreturn]] void __fish_assert(const char *msg, const char *file, size_t line, int error) { if (error) { - debug(0, L"%s:%zu: failed assertion: %s: errno %d (%s)", file, line, msg, error, - std::strerror(error)); + FLOG(error, L"%s:%zu: failed assertion: %s: errno %d (%s)", file, line, msg, error, + std::strerror(error)); } else { - debug(0, L"%s:%zu: failed assertion: %s", file, line, msg); + FLOG(error, L"%s:%zu: failed assertion: %s", file, line, msg); } show_stackframe(L'E', 99, 1); abort(); diff --git a/src/complete.cpp b/src/complete.cpp index bd0b4073f..5fb2fb987 100644 --- a/src/complete.cpp +++ b/src/complete.cpp @@ -904,7 +904,7 @@ bool completer_t::complete_param(const wcstring &cmd_orig, const wcstring &popt, } }; - // debug(0, L"\nThinking about looking up completions for %ls\n", cmd.c_str()); + // FLOG(error, L"\nThinking about looking up completions for %ls\n", cmd.c_str()); bool head_exists = builtin_exists(cmd); // Only reload environment variables if builtin_exists returned false, as an optimization if (head_exists == false) { diff --git a/src/env.cpp b/src/env.cpp index 6aa1fcd5d..51a372838 100644 --- a/src/env.cpp +++ b/src/env.cpp @@ -24,6 +24,7 @@ #include "event.h" #include "fallback.h" // IWYU pragma: keep #include "fish_version.h" +#include "flog.h" #include "global_safety.h" #include "history.h" #include "input.h" @@ -139,7 +140,7 @@ void fix_colon_delimited_var(const wcstring &var_name, env_stack_t &vars) { std::replace(newstrs.begin(), newstrs.end(), empty, wcstring(L".")); int retval = vars.set(var_name, ENV_DEFAULT | ENV_USER, std::move(newstrs)); if (retval != ENV_OK) { - debug(0, L"fix_colon_delimited_var failed unexpectedly with retval %d", retval); + FLOG(error, L"fix_colon_delimited_var failed unexpectedly with retval %d", retval); } } } @@ -1351,8 +1352,8 @@ wcstring env_get_runtime_path() { } if (!uname || check_runtime_path(tmpdir.c_str()) != 0) { - debug(0, L"Runtime path not available."); - debug(0, L"Try deleting the directory %s and restarting fish.", tmpdir.c_str()); + FLOG(error, L"Runtime path not available."); + FLOG(error, L"Try deleting the directory %s and restarting fish.", tmpdir.c_str()); return result; } diff --git a/src/env_universal_common.cpp b/src/env_universal_common.cpp index ad8867384..94d140caf 100644 --- a/src/env_universal_common.cpp +++ b/src/env_universal_common.cpp @@ -40,6 +40,7 @@ #include "env.h" #include "env_universal_common.h" #include "fallback.h" // IWYU pragma: keep +#include "flog.h" #include "path.h" #include "utf8.h" #include "util.h" // IWYU pragma: keep @@ -195,11 +196,11 @@ static bool append_file_entry(env_var_t::env_var_flags_t flags, const wcstring & // Append variable name like "fish_color_cwd". if (!valid_var_name(key_in)) { - debug(0, L"Illegal variable name: '%ls'", key_in.c_str()); + FLOG(error, L"Illegal variable name: '%ls'", key_in.c_str()); success = false; } if (success && !append_utf8(key_in, result, storage)) { - debug(0, L"Could not convert %ls to narrow character string", key_in.c_str()); + FLOG(error, L"Could not convert %ls to narrow character string", key_in.c_str()); success = false; } @@ -210,7 +211,7 @@ static bool append_file_entry(env_var_t::env_var_flags_t flags, const wcstring & // Append value. if (success && !append_utf8(full_escape(val_in), result, storage)) { - debug(0, L"Could not convert %ls to narrow character string", val_in.c_str()); + FLOG(error, L"Could not convert %ls to narrow character string", val_in.c_str()); success = false; } @@ -447,7 +448,8 @@ bool env_universal_t::write_to_fd(int fd, const wcstring &path) { std::string contents = serialize_with_vars(vars); if (write_loop(fd, contents.data(), contents.size()) < 0) { const char *error = std::strerror(errno); - debug(0, _(L"Unable to write to universal variables file '%ls': %s"), path.c_str(), error); + FLOG(error, _(L"Unable to write to universal variables file '%ls': %s"), path.c_str(), + error); success = false; } @@ -462,8 +464,8 @@ bool env_universal_t::move_new_vars_file_into_place(const wcstring &src, const w int ret = wrename(src, dst); if (ret != 0) { const char *error = std::strerror(errno); - debug(0, _(L"Unable to rename file from '%ls' to '%ls': %s"), src.c_str(), dst.c_str(), - error); + FLOG(error, _(L"Unable to rename file from '%ls' to '%ls': %s"), src.c_str(), dst.c_str(), + error); } return ret == 0; } @@ -525,7 +527,7 @@ bool env_universal_t::open_temporary_file(const wcstring &directory, wcstring *o if (!success) { const char *error = std::strerror(saved_errno); - debug(0, _(L"Unable to open temporary file '%ls': %s"), out_path->c_str(), error); + FLOG(error, _(L"Unable to open temporary file '%ls': %s"), out_path->c_str(), error); } return success; } @@ -587,7 +589,8 @@ bool env_universal_t::open_and_acquire_lock(const wcstring &path, int *out_fd) { } #endif const char *error = std::strerror(errno); - debug(0, _(L"Unable to open universal variable file '%ls': %s"), path.c_str(), error); + FLOG(error, _(L"Unable to open universal variable file '%ls': %s"), path.c_str(), + error); break; } @@ -1058,7 +1061,7 @@ class universal_notifier_shmem_poller_t : public universal_notifier_t { int fd = shm_open(path, O_RDWR | O_CREAT, 0600); if (fd < 0) { const char *error = std::strerror(errno); - debug(0, _(L"Unable to open shared memory with path '%s': %s"), path, error); + FLOG(error, _(L"Unable to open shared memory with path '%s': %s"), path, error); errored = true; } @@ -1068,8 +1071,8 @@ class universal_notifier_shmem_poller_t : public universal_notifier_t { struct stat buf = {}; if (fstat(fd, &buf) < 0) { const char *error = std::strerror(errno); - debug(0, _(L"Unable to fstat shared memory object with path '%s': %s"), path, - error); + FLOG(error, _(L"Unable to fstat shared memory object with path '%s': %s"), path, + error); errored = true; } size = buf.st_size; @@ -1079,7 +1082,8 @@ class universal_notifier_shmem_poller_t : public universal_notifier_t { bool set_size = !errored && size < (off_t)sizeof(universal_notifier_shmem_t); if (set_size && ftruncate(fd, sizeof(universal_notifier_shmem_t)) < 0) { const char *error = std::strerror(errno); - debug(0, _(L"Unable to truncate shared memory object with path '%s': %s"), path, error); + FLOG(error, _(L"Unable to truncate shared memory object with path '%s': %s"), path, + error); errored = true; } @@ -1089,8 +1093,8 @@ class universal_notifier_shmem_poller_t : public universal_notifier_t { MAP_SHARED, fd, 0); if (addr == MAP_FAILED) { const char *error = std::strerror(errno); - debug(0, _(L"Unable to memory map shared memory object with path '%s': %s"), path, - error); + FLOG(error, _(L"Unable to memory map shared memory object with path '%s': %s"), + path, error); this->region = NULL; } else { this->region = static_cast(addr); @@ -1495,7 +1499,7 @@ void universal_notifier_named_pipe_t::make_pipe(const wchar_t *test_path) { if (mkfifo_status == -1 && errno != EEXIST) { const char *error = std::strerror(errno); const wchar_t *errmsg = _(L"Unable to make a pipe for universal variables using '%ls': %s"); - debug(0, errmsg, vars_path.c_str(), error); + FLOG(error, errmsg, vars_path.c_str(), error); pipe_fd = -1; return; } @@ -1504,7 +1508,7 @@ void universal_notifier_named_pipe_t::make_pipe(const wchar_t *test_path) { if (fd < 0) { const char *error = std::strerror(errno); const wchar_t *errmsg = _(L"Unable to open a pipe for universal variables using '%ls': %s"); - debug(0, errmsg, vars_path.c_str(), error); + FLOG(error, errmsg, vars_path.c_str(), error); pipe_fd = -1; return; } diff --git a/src/exec.cpp b/src/exec.cpp index ce9b6568a..eb2f163ed 100644 --- a/src/exec.cpp +++ b/src/exec.cpp @@ -62,7 +62,7 @@ void exec_close(int fd) { // This may be called in a child of fork(), so don't allocate memory. if (fd < 0) { - debug(0, L"Called close on invalid file descriptor "); + FLOG(error, L"Called close on invalid file descriptor "); return; } @@ -614,20 +614,20 @@ static bool handle_builtin_output(parser_t &parser, const std::shared_ptr if (write_loop(STDOUT_FILENO, outbuff.data(), outbuff.size()) < 0) { if (errno != EPIPE) { did_err = true; - debug(0, "Error while writing to stdout"); + FLOG(error, "Error while writing to stdout"); wperror(L"write_loop"); } } if (write_loop(STDERR_FILENO, errbuff.data(), errbuff.size()) < 0) { if (errno != EPIPE && !did_err) { did_err = true; - debug(0, "Error while writing to stderr"); + FLOG(error, "Error while writing to stderr"); wperror(L"write_loop"); } } if (did_err) { redirect_tty_output(); // workaround glibc bug - debug(0, "!builtin_io_done and errno != EPIPE"); + FLOG(error, "!builtin_io_done and errno != EPIPE"); show_stackframe(L'E'); } // Clear the buffers to indicate we finished. @@ -789,7 +789,7 @@ static bool exec_block_or_func_process(parser_t &parser, std::shared_ptr const wcstring func_name = p->argv0(); auto props = function_get_properties(func_name); if (!props) { - debug(0, _(L"Unknown function '%ls'"), p->argv0()); + FLOG(error, _(L"Unknown function '%ls'"), p->argv0()); return false; } diff --git a/src/expand.cpp b/src/expand.cpp index a2bae217c..d6c55c1b0 100644 --- a/src/expand.cpp +++ b/src/expand.cpp @@ -222,7 +222,7 @@ static size_t parse_slice(const wchar_t *in, wchar_t **end_ptr, std::vector 0) { - // debug(0, L"Item is deleted : %s\n", old_item.str().c_str()); + // FLOG(error, L"Item is deleted : %s\n", old_item.str().c_str()); continue; } // Add this old item. diff --git a/src/iothread.cpp b/src/iothread.cpp index eb07ac854..f206e776a 100644 --- a/src/iothread.cpp +++ b/src/iothread.cpp @@ -15,6 +15,7 @@ #include #include "common.h" +#include "flog.h" #include "global_safety.h" #include "iothread.h" #include "wutil.h" @@ -201,7 +202,7 @@ void iothread_service_completion() { } else if (wakeup_byte == IO_SERVICE_RESULT_QUEUE) { iothread_service_result_queue(); } else { - debug(0, "Unknown wakeup byte %02x in %s", wakeup_byte, __FUNCTION__); + FLOG(error, "Unknown wakeup byte %02x in %s", wakeup_byte, __FUNCTION__); } } diff --git a/src/output.cpp b/src/output.cpp index 80f0f51d8..5ce29e547 100644 --- a/src/output.cpp +++ b/src/output.cpp @@ -27,6 +27,7 @@ #include "common.h" #include "env.h" #include "fallback.h" // IWYU pragma: keep +#include "flog.h" #include "output.h" #include "wutil.h" // IWYU pragma: keep @@ -528,7 +529,7 @@ void writembs_check(outputter_t &outp, const char *mbs, const char *mbs_name, bo const wchar_t *fmt = _(L"Tried to use terminfo string %s on line %ld of %s, which is " L"undefined in terminal of type \"%ls\". Please report this error to %s"); - debug(0, fmt, mbs_name, line, file, term ? term->as_string().c_str() : L"", - PACKAGE_BUGREPORT); + FLOG(error, fmt, mbs_name, line, file, term ? term->as_string().c_str() : L"", + PACKAGE_BUGREPORT); } } diff --git a/src/parse_constants.h b/src/parse_constants.h index 2879bc251..897c6fabf 100644 --- a/src/parse_constants.h +++ b/src/parse_constants.h @@ -8,7 +8,7 @@ #define PARSE_ASSERT(a) assert(a) #define PARSER_DIE() \ do { \ - debug(0, "Parser dying!"); \ + FLOG(error, "Parser dying!"); \ exit_without_destructors(-1); \ } while (0) diff --git a/src/parse_execution.cpp b/src/parse_execution.cpp index 235235dfb..1f9d7d13c 100644 --- a/src/parse_execution.cpp +++ b/src/parse_execution.cpp @@ -31,6 +31,7 @@ #include "event.h" #include "exec.h" #include "expand.h" +#include "flog.h" #include "function.h" #include "io.h" #include "maybe.h" @@ -358,7 +359,7 @@ parse_execution_result_t parse_execution_context_t::run_block_statement( } else if (auto header = bheader.try_get_child()) { ret = run_begin_statement(contents); } else { - debug(0, L"Unexpected block header: %ls\n", bheader.node()->describe().c_str()); + FLOG(error, L"Unexpected block header: %ls\n", bheader.node()->describe().c_str()); PARSER_DIE(); } return ret; @@ -635,7 +636,7 @@ parse_execution_result_t parse_execution_context_t::report_errors( const parse_error_list_t &error_list) const { if (!parser->cancellation_requested) { if (error_list.empty()) { - debug(0, "Error reported but no error text found."); + FLOG(error, "Error reported but no error text found."); } // Get a backtrace. @@ -1076,8 +1077,8 @@ parse_execution_result_t parse_execution_context_t::populate_job_process( break; } default: { - debug(0, L"'%ls' not handled by new parser yet.", - specific_statement.describe().c_str()); + FLOG(error, L"'%ls' not handled by new parser yet.", + specific_statement.describe().c_str()); PARSER_DIE(); break; } @@ -1380,8 +1381,8 @@ parse_execution_result_t parse_execution_context_t::eval_node(tnode_t()) { status = this->run_switch_statement(switchstat); } else { - debug(0, "Unexpected node %ls found in %s", statement.node()->describe().c_str(), - __FUNCTION__); + FLOG(error, "Unexpected node %ls found in %s", statement.node()->describe().c_str(), + __FUNCTION__); abort(); } return status; diff --git a/src/parse_productions.cpp b/src/parse_productions.cpp index 2d30fefc5..5dc43aea1 100644 --- a/src/parse_productions.cpp +++ b/src/parse_productions.cpp @@ -3,6 +3,7 @@ #include #include "common.h" +#include "flog.h" #include "parse_constants.h" #include "parse_grammar.h" #include "parse_productions.h" @@ -402,21 +403,21 @@ const production_element_t *parse_productions::production_for_token(parse_token_ case parse_token_type_oror: case parse_token_type_end: case parse_token_type_terminate: { - debug(0, "Terminal token type %ls passed to %s", token_type_description(node_type), - __FUNCTION__); + FLOG(error, "Terminal token type %ls passed to %s", token_type_description(node_type), + __FUNCTION__); PARSER_DIE(); break; } case parse_special_type_parse_error: case parse_special_type_tokenizer_error: case parse_special_type_comment: { - debug(0, "Special type %ls passed to %s\n", token_type_description(node_type), - __FUNCTION__); + FLOG(error, "Special type %ls passed to %s\n", token_type_description(node_type), + __FUNCTION__); PARSER_DIE(); break; } case token_type_invalid: { - debug(0, "token_type_invalid passed to %s", __FUNCTION__); + FLOG(error, "token_type_invalid passed to %s", __FUNCTION__); PARSER_DIE(); break; } diff --git a/src/parse_tree.cpp b/src/parse_tree.cpp index 3b8c374ce..08aedba62 100644 --- a/src/parse_tree.cpp +++ b/src/parse_tree.cpp @@ -13,6 +13,7 @@ #include "common.h" #include "fallback.h" +#include "flog.h" #include "parse_constants.h" #include "parse_productions.h" #include "parse_tree.h" @@ -256,7 +257,7 @@ static inline parse_token_type_t parse_token_type_from_tokenizer_token( case TOK_COMMENT: return parse_special_type_comment; } - debug(0, "Bad token type %d passed to %s", (int)tokenizer_token_type, __FUNCTION__); + FLOG(error, "Bad token type %d passed to %s", (int)tokenizer_token_type, __FUNCTION__); DIE("bad token type"); return token_type_invalid; } diff --git a/src/path.cpp b/src/path.cpp index d5ab52c66..7e1f9ff16 100644 --- a/src/path.cpp +++ b/src/path.cpp @@ -18,6 +18,7 @@ #include "env.h" #include "expand.h" #include "fallback.h" // IWYU pragma: keep +#include "flog.h" #include "path.h" #include "wutil.h" // IWYU pragma: keep @@ -267,17 +268,17 @@ static void maybe_issue_path_warning(const wcstring &which_dir, const wcstring & } vars.set_one(warning_var_name, ENV_GLOBAL | ENV_EXPORT, L"1"); - debug(0, custom_error_msg.c_str()); + FLOG(error, custom_error_msg.c_str()); if (path.empty()) { - debug(0, _(L"Unable to locate the %ls directory."), which_dir.c_str()); - debug(0, _(L"Please set the %ls or HOME environment variable before starting fish."), - xdg_var.c_str()); + FLOG(error, _(L"Unable to locate the %ls directory."), which_dir.c_str()); + FLOG(error, _(L"Please set the %ls or HOME environment variable before starting fish."), + xdg_var.c_str()); } else { const wchar_t *env_var = using_xdg ? xdg_var.c_str() : L"HOME"; - debug(0, _(L"Unable to locate %ls directory derived from $%ls: '%ls'."), which_dir.c_str(), - env_var, path.c_str()); - debug(0, _(L"The error was '%s'."), std::strerror(saved_errno)); - debug(0, _(L"Please set $%ls to a directory where you have write access."), env_var); + FLOG(error, _(L"Unable to locate %ls directory derived from $%ls: '%ls'."), + which_dir.c_str(), env_var, path.c_str()); + FLOG(error, _(L"The error was '%s'."), std::strerror(saved_errno)); + FLOG(error, _(L"Please set $%ls to a directory where you have write access."), env_var); } ignore_result(write(STDERR_FILENO, "\n", 1)); } diff --git a/src/postfork.cpp b/src/postfork.cpp index 0fbd442cb..c8a4b2add 100644 --- a/src/postfork.cpp +++ b/src/postfork.cpp @@ -374,7 +374,7 @@ void safe_report_exec_error(int err, const char *actual_cmd, const char *const * const char *err = safe_strerror(errno); debug_safe(0, "exec: %s", err); - // debug(0, L"The file '%ls' is marked as an executable but could not be run by the + // FLOG(error, L"The file '%ls' is marked as an executable but could not be run by the // operating system.", p->actual_cmd); break; } diff --git a/src/proc.cpp b/src/proc.cpp index 7ccda9b4d..b5165cba4 100644 --- a/src/proc.cpp +++ b/src/proc.cpp @@ -914,8 +914,8 @@ void proc_sanity_check(const parser_t &parser) { // More than one foreground job? if (j->is_foreground() && !(j->is_stopped() || j->is_completed())) { if (fg_job) { - debug(0, _(L"More than one job in foreground: job 1: '%ls' job 2: '%ls'"), - fg_job->command_wcstr(), j->command_wcstr()); + FLOG(error, _(L"More than one job in foreground: job 1: '%ls' job 2: '%ls'"), + fg_job->command_wcstr(), j->command_wcstr()); sanity_lose(); } fg_job = j.get(); @@ -928,14 +928,14 @@ void proc_sanity_check(const parser_t &parser) { validate_pointer(p->argv0(), _(L"Process name"), null_ok); if ((p->stopped & (~0x00000001)) != 0) { - debug(0, _(L"Job '%ls', process '%ls' has inconsistent state \'stopped\'=%d"), - j->command_wcstr(), p->argv0(), p->stopped); + FLOG(error, _(L"Job '%ls', process '%ls' has inconsistent state \'stopped\'=%d"), + j->command_wcstr(), p->argv0(), p->stopped); sanity_lose(); } if ((p->completed & (~0x00000001)) != 0) { - debug(0, _(L"Job '%ls', process '%ls' has inconsistent state \'completed\'=%d"), - j->command_wcstr(), p->argv0(), p->completed); + FLOG(error, _(L"Job '%ls', process '%ls' has inconsistent state \'completed\'=%d"), + j->command_wcstr(), p->argv0(), p->completed); sanity_lose(); } } diff --git a/src/reader.cpp b/src/reader.cpp index 0a94bc8d0..4a18a7220 100644 --- a/src/reader.cpp +++ b/src/reader.cpp @@ -52,6 +52,7 @@ #include "exec.h" #include "expand.h" #include "fallback.h" // IWYU pragma: keep +#include "flog.h" #include "function.h" #include "global_safety.h" #include "highlight.h" @@ -1749,7 +1750,7 @@ static void reader_interactive_init() { if (shell_pgid == 0) { shell_pgid = getpid(); if (setpgid(shell_pgid, shell_pgid) < 0) { - debug(0, _(L"Failed to assign shell to its own process group")); + FLOG(error, _(L"Failed to assign shell to its own process group")); wperror(L"setpgid"); exit_without_destructors(1); } @@ -1759,7 +1760,7 @@ static void reader_interactive_init() { if (errno == ENOTTY) { redirect_tty_output(); } - debug(0, _(L"Failed to take control of the terminal")); + FLOG(error, _(L"Failed to take control of the terminal")); wperror(L"tcsetpgrp"); exit_without_destructors(1); } diff --git a/src/sanity.cpp b/src/sanity.cpp index 804665151..4bc6b540c 100644 --- a/src/sanity.cpp +++ b/src/sanity.cpp @@ -5,6 +5,7 @@ #include "common.h" #include "fallback.h" // IWYU pragma: keep +#include "flog.h" #include "global_safety.h" #include "history.h" #include "kill.h" @@ -16,19 +17,19 @@ static relaxed_atomic_bool_t insane{false}; void sanity_lose() { - debug(0, _(L"Errors detected, shutting down. Break on sanity_lose() to debug.")); + FLOG(error, _(L"Errors detected, shutting down. Break on sanity_lose() to debug.")); insane = true; } void validate_pointer(const void *ptr, const wchar_t *err, int null_ok) { // Test if the pointer data crosses a segment boundary. if ((0x00000003l & (intptr_t)ptr) != 0) { - debug(0, _(L"The pointer '%ls' is invalid"), err); + FLOG(error, _(L"The pointer '%ls' is invalid"), err); sanity_lose(); } if ((!null_ok) && (ptr == 0)) { - debug(0, _(L"The pointer '%ls' is null"), err); + FLOG(error, _(L"The pointer '%ls' is null"), err); sanity_lose(); } } diff --git a/src/tokenizer.cpp b/src/tokenizer.cpp index d1f4f4a97..0308d8f53 100644 --- a/src/tokenizer.cpp +++ b/src/tokenizer.cpp @@ -243,7 +243,7 @@ tok_t tokenizer_t::read_string() { } else { msg.push_back(L'\n'); } - debug(0, msg.c_str(), c, c, int(mode_begin), int(mode)); + FLOG(error, msg.c_str(), c, c, int(mode_begin), int(mode)); #endif this->buff++; diff --git a/src/wutil.cpp b/src/wutil.cpp index b9998f6b6..f5e245239 100644 --- a/src/wutil.cpp +++ b/src/wutil.cpp @@ -27,6 +27,7 @@ #include "common.h" #include "fallback.h" // IWYU pragma: keep +#include "flog.h" #include "wutil.h" // IWYU pragma: keep typedef std::string cstring; @@ -130,7 +131,7 @@ const wcstring wgetcwd() { return str2wcstring(res); } - debug(0, _(L"getcwd() failed with errno %d/%s"), errno, std::strerror(errno)); + FLOG(error, _(L"getcwd() failed with errno %d/%s"), errno, std::strerror(errno)); return wcstring(); } From 0150d505debd95e8786b138972ecc4aba33a4a37 Mon Sep 17 00:00:00 2001 From: ridiculousfish Date: Mon, 27 May 2019 17:38:09 -0700 Subject: [PATCH 7/7] Allow underscores to be treated as dashes in debug categories --- src/flog.cpp | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/src/flog.cpp b/src/flog.cpp index 490b78ee5..9a9bfa3e1 100644 --- a/src/flog.cpp +++ b/src/flog.cpp @@ -73,7 +73,10 @@ static void apply_one_wildcard(const wcstring &wc_esc, bool sense) { } } -void activate_flog_categories_by_pattern(const wcstring &wc) { +void activate_flog_categories_by_pattern(const wcstring &inwc) { + // Normalize underscores to dashes, allowing the user to be sloppy. + wcstring wc = inwc; + std::replace(wc.begin(), wc.end(), L'_', L'-'); for (const wcstring &s : split_string(wc, L',')) { if (string_prefixes_string(s, L"-")) { apply_one_wildcard(s.substr(1), false);