From 384f18a51c138a6786349637de89902d7ee8a270 Mon Sep 17 00:00:00 2001 From: Fabian Homborg Date: Sun, 19 Jan 2020 13:31:25 +0100 Subject: [PATCH 01/19] Remove last remaining debug(0) Replace with FLOGF. --- src/common.cpp | 2 +- src/reader.cpp | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/src/common.cpp b/src/common.cpp index 3fd2da590..3ede77e2c 100644 --- a/src/common.cpp +++ b/src/common.cpp @@ -184,7 +184,7 @@ bool is_windows_subsystem_for_linux() { // is bypassed. We intentionally do not include this in the error message because // it'll only allow fish to run but not to actually work. Here be dragons! if (getenv("FISH_NO_WSL_CHECK") == nullptr) { - debug(0, + FLOGF(error, "This version of WSL has known bugs that prevent fish from working." "Please upgrade to Windows 10 1809 (17763) or higher to use fish!"); } diff --git a/src/reader.cpp b/src/reader.cpp index 62c7d4938..3cf7a7654 100644 --- a/src/reader.cpp +++ b/src/reader.cpp @@ -3514,7 +3514,7 @@ static int read_ni(parser_t &parser, int fd, const io_chain_t &io) { clearerr(in_stream); } else { // Fatal error. - debug(0, _(L"Unable to read input file: %s"), strerror(errno)); + FLOGF(error, _(L"Unable to read input file: %s"), strerror(errno)); // Reset buffer on error. We won't evaluate incomplete files. acc.clear(); break; From 024e03ab1e2757e41146fdbac7ddab94a55dea3e Mon Sep 17 00:00:00 2001 From: Fabian Homborg Date: Sun, 19 Jan 2020 13:38:47 +0100 Subject: [PATCH 02/19] Replace debug(1) with FLOGF(warning) --- src/common.cpp | 8 ++++---- src/env_dispatch.cpp | 14 +++++++------- src/env_universal_common.cpp | 16 ++++++++-------- src/exec.cpp | 6 +++--- src/fish.cpp | 4 ++-- src/fish_indent.cpp | 3 ++- src/flog.h | 2 ++ src/history.cpp | 2 +- src/io.cpp | 8 ++++---- src/io.h | 1 + src/output.cpp | 2 +- src/parser.cpp | 2 +- src/path.cpp | 2 +- src/proc.cpp | 10 +++++----- src/reader.cpp | 14 +++++++------- 15 files changed, 49 insertions(+), 45 deletions(-) diff --git a/src/common.cpp b/src/common.cpp index 3ede77e2c..1e3feac5b 100644 --- a/src/common.cpp +++ b/src/common.cpp @@ -1777,8 +1777,8 @@ static void validate_new_termsize(struct winsize *new_termsize, const environmen #ifdef HAVE_WINSIZE // Highly hackish. This seems like it should be moved. if (is_main_thread() && parser_t::principal_parser().is_interactive()) { - debug(1, _(L"Current terminal parameters have rows and/or columns set to zero.")); - debug(1, _(L"The stty command can be used to correct this " + FLOGF(warning, _(L"Current terminal parameters have rows and/or columns set to zero.")); + FLOGF(warning, _(L"The stty command can be used to correct this " L"(e.g., stty rows 80 columns 24).")); } #endif @@ -1801,8 +1801,8 @@ static void validate_new_termsize(struct winsize *new_termsize, const environmen if (new_termsize->ws_col < MIN_TERM_COL || new_termsize->ws_row < MIN_TERM_ROW) { // Also highly hackisk. if (is_main_thread() && parser_t::principal_parser().is_interactive()) { - debug(1, _(L"Current terminal parameters set terminal size to unreasonable value.")); - debug(1, _(L"Defaulting terminal size to 80x24.")); + FLOGF(warning, _(L"Current terminal parameters set terminal size to unreasonable value.")); + FLOGF(warning, _(L"Defaulting terminal size to 80x24.")); } new_termsize->ws_col = DFLT_TERM_COL; new_termsize->ws_row = DFLT_TERM_ROW; diff --git a/src/env_dispatch.cpp b/src/env_dispatch.cpp index 41ce0cf62..5d26a6b41 100644 --- a/src/env_dispatch.cpp +++ b/src/env_dispatch.cpp @@ -277,7 +277,7 @@ static void handle_read_limit_change(const environment_t &vars) { if (!read_byte_limit_var.missing_or_empty()) { size_t limit = fish_wcstoull(read_byte_limit_var->as_string().c_str()); if (errno) { - debug(1, "Ignoring fish_read_limit since it is not valid"); + FLOGF(warning, "Ignoring fish_read_limit since it is not valid"); } else { read_byte_limit = limit; } @@ -395,12 +395,12 @@ static bool initialize_curses_using_fallback(const char *term) { if (term_env == DEFAULT_TERM1 || term_env == DEFAULT_TERM2) return false; if (session_interactivity() != session_interactivity_t::not_interactive) - debug(1, _(L"Using fallback terminal type '%s'."), term); + FLOGF(warning, _(L"Using fallback terminal type '%s'."), term); int err_ret; if (setupterm(const_cast(term), STDOUT_FILENO, &err_ret) == OK) return true; if (session_interactivity() != session_interactivity_t::not_interactive) { - debug(1, _(L"Could not set up terminal using the fallback terminal type '%s'."), term); + FLOGF(warning, _(L"Could not set up terminal using the fallback terminal type '%s'."), term); } return false; } @@ -459,12 +459,12 @@ static void init_curses(const environment_t &vars) { if (setupterm(nullptr, STDOUT_FILENO, &err_ret) == ERR) { auto term = vars.get(L"TERM"); if (session_interactivity() != session_interactivity_t::not_interactive) { - debug(1, _(L"Could not set up terminal.")); + FLOGF(warning, _(L"Could not set up terminal.")); if (term.missing_or_empty()) { - debug(1, _(L"TERM environment variable not set.")); + FLOGF(warning, _(L"TERM environment variable not set.")); } else { - debug(1, _(L"TERM environment variable set to '%ls'."), term->as_string().c_str()); - debug(1, _(L"Check that this terminal type is supported on this system.")); + FLOGF(warning, _(L"TERM environment variable set to '%ls'."), term->as_string().c_str()); + FLOGF(warning, _(L"Check that this terminal type is supported on this system.")); } } diff --git a/src/env_universal_common.cpp b/src/env_universal_common.cpp index 8c5885b96..d8860cbd6 100644 --- a/src/env_universal_common.cpp +++ b/src/env_universal_common.cpp @@ -554,7 +554,7 @@ bool env_universal_t::open_temporary_file(const wcstring &directory, wcstring *o static bool check_duration(double start_time) { double duration = timef() - start_time; if (duration > 0.25) { - debug(1, _(L"Locking the universal var file took too long (%.3f seconds)."), duration); + FLOGF(warning, _(L"Locking the universal var file took too long (%.3f seconds)."), duration); return false; } return true; @@ -902,7 +902,7 @@ void env_universal_t::parse_message_30_internal(const wcstring &msgstr, var_tabl const wchar_t *cursor = msg; if (!match(&cursor, f3::SETUVAR)) { - debug(1, PARSE_ERR, msg); + FLOGF(warning, PARSE_ERR, msg); return; } // Parse out flags. @@ -922,7 +922,7 @@ void env_universal_t::parse_message_30_internal(const wcstring &msgstr, var_tabl // Populate the variable with these flags. if (!populate_1_variable(cursor, flags, vars, storage)) { - debug(1, PARSE_ERR, msg); + FLOGF(warning, PARSE_ERR, msg); } } @@ -942,12 +942,12 @@ void env_universal_t::parse_message_2x_internal(const wcstring &msgstr, var_tabl } else if (match(&cursor, f2x::SET)) { flags |= 0; } else { - debug(1, PARSE_ERR, msg); + FLOGF(warning, PARSE_ERR, msg); return; } if (!populate_1_variable(cursor, flags, vars, storage)) { - debug(1, PARSE_ERR, msg); + FLOGF(warning, PARSE_ERR, msg); } } @@ -1216,8 +1216,8 @@ class universal_notifier_notifyd_t : public universal_notifier_t { uint32_t status = notify_register_file_descriptor(name.c_str(), &this->notify_fd, 0, &this->token); if (status != NOTIFY_STATUS_OK) { - debug(1, "notify_register_file_descriptor() failed with status %u.", status); - debug(1, "Universal variable notifications may not be received."); + FLOGF(warning, "notify_register_file_descriptor() failed with status %u.", status); + FLOGF(warning, "Universal variable notifications may not be received."); } if (this->notify_fd >= 0) { // Mark us for non-blocking reads, and CLO_EXEC. @@ -1265,7 +1265,7 @@ class universal_notifier_notifyd_t : public universal_notifier_t { void post_notification() { uint32_t status = notify_post(name.c_str()); if (status != NOTIFY_STATUS_OK) { - debug(1, "notify_post() failed with status %u. Uvar notifications may not be sent.", + FLOGF(warning, "notify_post() failed with status %u. Uvar notifications may not be sent.", status); } } diff --git a/src/exec.cpp b/src/exec.cpp index 304b5a287..026bfa4ef 100644 --- a/src/exec.cpp +++ b/src/exec.cpp @@ -66,7 +66,7 @@ void exec_close(int fd) { while (close(fd) == -1) { if (errno != EINTR) { - debug(1, FD_ERROR, fd); + FLOGF(warning, FD_ERROR, fd); wperror(L"close"); break; } @@ -364,7 +364,7 @@ static bool fork_child_for_process(const std::shared_ptr &job, process_t } if (pid < 0) { - debug(1, L"Failed to fork %s!\n", fork_type); + FLOGF(warning, L"Failed to fork %s!\n", fork_type); job_mark_process_as_failed(job, p); return false; } @@ -1073,7 +1073,7 @@ bool exec_job(parser_t &parser, const shared_ptr &j, const job_lineage_t if (!p->is_last_in_job) { auto pipes = make_autoclose_pipes(conflicts); if (!pipes) { - debug(1, PIPE_ERROR); + FLOGF(warning, PIPE_ERROR); wperror(L"pipe"); job_mark_process_as_failed(j, p.get()); exec_error = true; diff --git a/src/fish.cpp b/src/fish.cpp index 57573a25d..72965610f 100644 --- a/src/fish.cpp +++ b/src/fish.cpp @@ -438,7 +438,7 @@ int main(int argc, char **argv) { // 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")); + FLOGF(warning, _(L"Can not use the no-execute mode when running an interactive session")); opts.no_exec = false; } @@ -513,7 +513,7 @@ int main(int argc, char **argv) { intern(rel_filename.c_str())}; res = reader_read(parser, fd, {}); if (res) { - debug(1, _(L"Error while reading file %ls\n"), + FLOGF(warning, _(L"Error while reading file %ls\n"), ld.current_filename ? ld.current_filename : _(L"Standard input")); } } diff --git a/src/fish_indent.cpp b/src/fish_indent.cpp index 35a2546b0..dbf496cc7 100644 --- a/src/fish_indent.cpp +++ b/src/fish_indent.cpp @@ -37,6 +37,7 @@ Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA #include "common.h" #include "env.h" #include "fish_version.h" +#include "flog.h" #include "highlight.h" #include "operation_context.h" #include "output.h" @@ -64,7 +65,7 @@ static wcstring read_file(FILE *f) { // Illegal byte sequence. Try to skip past it. clearerr(f); int ch = fgetc(f); // for printing the warning, and seeks forward 1 byte. - debug(1, "%s (byte=%X)", std::strerror(errno), ch); + FLOGF(warning, "%s (byte=%X)", std::strerror(errno), ch); ret = 1; continue; } else { diff --git a/src/flog.h b/src/flog.h index 9c478fe28..7f61d2988 100644 --- a/src/flog.h +++ b/src/flog.h @@ -51,6 +51,8 @@ class category_list_t { category_t debug{L"debug", L"Debugging aid (on by default)", true}; + category_t warning{L"warning", L"Warnings (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"}; diff --git a/src/history.cpp b/src/history.cpp index 9c53de01a..89fbd199f 100644 --- a/src/history.cpp +++ b/src/history.cpp @@ -131,7 +131,7 @@ static bool history_file_lock(int fd, int lock_type) { int retval = flock(fd, lock_type); double duration = timef() - start_time; if (duration > 0.25) { - debug(1, _(L"Locking the history file took too long (%.3f seconds)."), duration); + FLOGF(warning, _(L"Locking the history file took too long (%.3f seconds)."), duration); // we've decided to stop doing any locking behavior // but make sure we don't leave the file locked! if (retval == 0 && lock_type != LOCK_UN) { diff --git a/src/io.cpp b/src/io.cpp index a28f61010..ed241237b 100644 --- a/src/io.cpp +++ b/src/io.cpp @@ -185,7 +185,7 @@ shared_ptr io_bufferfill_t::create(const fd_set_t &conflicts, // because our fillthread needs to poll to decide if it should shut down, and also accept input // from direct buffer transfers. if (make_fd_nonblocking(pipes->read.fd())) { - debug(1, PIPE_ERROR); + FLOGF(warning, PIPE_ERROR); wperror(L"fcntl"); return nullptr; } @@ -254,9 +254,9 @@ bool io_chain_t::append_from_specs(const redirection_spec_list_t &specs, const w autoclose_fd_t file{wopen_cloexec(path, oflags, OPEN_MASK)}; if (!file.valid()) { if ((oflags & O_EXCL) && (errno == EEXIST)) { - debug(1, NOCLOB_ERROR, spec.target.c_str()); + FLOGF(warning, NOCLOB_ERROR, spec.target.c_str()); } else { - debug(1, FILE_ERROR, spec.target.c_str()); + FLOGF(warning, FILE_ERROR, spec.target.c_str()); if (should_debug(1)) wperror(L"open"); } return false; @@ -321,7 +321,7 @@ maybe_t make_autoclose_pipes(const fd_set_t &fdset) { int pipes[2] = {-1, -1}; if (pipe(pipes) < 0) { - debug(1, PIPE_ERROR); + FLOGF(warning, PIPE_ERROR); wperror(L"pipe"); return none(); } diff --git a/src/io.h b/src/io.h index 7503b664e..51c996d6a 100644 --- a/src/io.h +++ b/src/io.h @@ -14,6 +14,7 @@ #include "common.h" #include "env.h" +#include "flog.h" #include "global_safety.h" #include "maybe.h" #include "redirection.h" diff --git a/src/output.cpp b/src/output.cpp index 501d3ecd3..b646b3076 100644 --- a/src/output.cpp +++ b/src/output.cpp @@ -404,7 +404,7 @@ void outputter_t::writestr(const wchar_t *str) { size_t len = wcstombs(nullptr, str, 0); // figure amount of space needed if (len == static_cast(-1)) { - debug(1, L"Tried to print invalid wide character string"); + FLOGF(warning, L"Tried to print invalid wide character string"); return; } diff --git a/src/parser.cpp b/src/parser.cpp index 381b8ac06..c55d54dd8 100644 --- a/src/parser.cpp +++ b/src/parser.cpp @@ -291,7 +291,7 @@ void parser_t::emit_profiling(const char *path) const { // dying (and hence will not fork). FILE *f = fopen(path, "w"); if (!f) { - debug(1, _(L"Could not write profiling information to file '%s'"), path); + FLOGF(warning, _(L"Could not write profiling information to file '%s'"), path); } else { if (std::fwprintf(f, _(L"Time\tSum\tCommand\n"), profile_items.size()) < 0) { wperror(L"fwprintf"); diff --git a/src/path.cpp b/src/path.cpp index 3e2995103..a6271adaa 100644 --- a/src/path.cpp +++ b/src/path.cpp @@ -107,7 +107,7 @@ static bool path_get_path_core(const wcstring &cmd, wcstring *out_path, break; } default: { - debug(1, MISSING_COMMAND_ERR_MSG, next_path.c_str()); + FLOGF(warning, MISSING_COMMAND_ERR_MSG, next_path.c_str()); wperror(L"access"); break; } diff --git a/src/proc.cpp b/src/proc.cpp index c20e543a3..c018dbae1 100644 --- a/src/proc.cpp +++ b/src/proc.cpp @@ -743,7 +743,7 @@ int terminal_maybe_give_to_job(const job_t *j, bool continuing_from_stopped) { if (errno == ENOTTY) { redirect_tty_output(); } - debug(1, _(L"Could not send job %d ('%ls') with pgid %d to foreground"), + FLOGF(warning, _(L"Could not send job %d ('%ls') with pgid %d to foreground"), j->job_id(), j->command_wcstr(), j->pgid); wperror(L"tcsetpgrp"); return error; @@ -771,7 +771,7 @@ int terminal_maybe_give_to_job(const job_t *j, bool continuing_from_stopped) { redirect_tty_output(); } - debug(1, _(L"Could not send job %d ('%ls') to foreground"), j->job_id(), + FLOGF(warning, _(L"Could not send job %d ('%ls') to foreground"), j->job_id(), j->preview().c_str()); wperror(L"tcsetattr"); return error; @@ -804,7 +804,7 @@ static bool terminal_return_from_job(job_t *j, int restore_attrs) { if (tcsetpgrp(STDIN_FILENO, getpgrp()) == -1) { if (errno == ENOTTY) redirect_tty_output(); - debug(1, _(L"Could not return shell to foreground")); + FLOGF(warning, _(L"Could not return shell to foreground")); wperror(L"tcsetpgrp"); return false; } @@ -812,7 +812,7 @@ static bool terminal_return_from_job(job_t *j, int restore_attrs) { // Save jobs terminal modes. if (tcgetattr(STDIN_FILENO, &j->tmodes)) { if (errno == EIO) redirect_tty_output(); - debug(1, _(L"Could not return shell to foreground")); + FLOGF(warning, _(L"Could not return shell to foreground")); wperror(L"tcgetattr"); return false; } @@ -823,7 +823,7 @@ static bool terminal_return_from_job(job_t *j, int restore_attrs) { if (restore_attrs) { if (tcsetattr(STDIN_FILENO, TCSADRAIN, &shell_modes) == -1) { if (errno == EIO) redirect_tty_output(); - debug(1, _(L"Could not return shell to foreground")); + FLOGF(warning, _(L"Could not return shell to foreground")); wperror(L"tcsetattr"); return false; } diff --git a/src/reader.cpp b/src/reader.cpp index 3cf7a7654..a7b0468ff 100644 --- a/src/reader.cpp +++ b/src/reader.cpp @@ -529,7 +529,7 @@ static void term_donate(outputter_t &outp) { if (tcsetattr(STDIN_FILENO, TCSANOW, &tty_modes_for_external_cmds) == -1) { if (errno == EIO) redirect_tty_output(); if (errno != EINTR) { - debug(1, _(L"Could not set terminal mode for new job")); + FLOGF(warning, _(L"Could not set terminal mode for new job")); wperror(L"tcsetattr"); break; } @@ -544,7 +544,7 @@ static void term_steal() { if (tcsetattr(STDIN_FILENO, TCSANOW, &shell_modes) == -1) { if (errno == EIO) redirect_tty_output(); if (errno != EINTR) { - debug(1, _(L"Could not set terminal mode for shell")); + FLOGF(warning, _(L"Could not set terminal mode for shell")); perror("tcsetattr"); break; } @@ -1736,7 +1736,7 @@ static void reader_interactive_init(parser_t &parser) { } // No TTY, cannot be interactive? redirect_tty_output(); - debug(1, _(L"No TTY for interactive shell (tcgetpgrp failed)")); + FLOGF(warning, _(L"No TTY for interactive shell (tcgetpgrp failed)")); wperror(L"setpgid"); exit_without_destructors(1); } @@ -1748,7 +1748,7 @@ static void reader_interactive_init(parser_t &parser) { const wchar_t *fmt = _(L"I appear to be an orphaned process, so I am quitting politely. " L"My pid is %d."); - debug(1, fmt, (int)getpid()); + FLOGF(warning, fmt, (int)getpid()); exit_without_destructors(1); } @@ -1797,7 +1797,7 @@ static void reader_interactive_init(parser_t &parser) { if (errno == EIO) { redirect_tty_output(); } - debug(1, _(L"Failed to set startup terminal mode!")); + FLOGF(warning, _(L"Failed to set startup terminal mode!")); wperror(L"tcsetattr"); } } @@ -3528,7 +3528,7 @@ static int read_ni(parser_t &parser, int fd, const io_chain_t &io) { acc.clear(); if (fclose(in_stream)) { - debug(1, _(L"Error while closing input stream")); + FLOGF(warning, _(L"Error while closing input stream")); wperror(L"fclose"); res = 1; } @@ -3550,7 +3550,7 @@ static int read_ni(parser_t &parser, int fd, const io_chain_t &io) { res = 1; } } else { - debug(1, _(L"Error while opening input stream")); + FLOGF(warning, _(L"Error while opening input stream")); wperror(L"fdopen"); res = 1; } From 4e0ec080e33d3a00212430501f643c8db1cbcce0 Mon Sep 17 00:00:00 2001 From: Fabian Homborg Date: Sun, 19 Jan 2020 13:39:23 +0100 Subject: [PATCH 03/19] Add flog category for terminal support This is meant to show messages related to what a terminal supports. In particular which color or emoji it can handle. --- src/env_dispatch.cpp | 24 ++++++++++++------------ src/flog.h | 2 ++ 2 files changed, 14 insertions(+), 12 deletions(-) diff --git a/src/env_dispatch.cpp b/src/env_dispatch.cpp index 5d26a6b41..25927e2c5 100644 --- a/src/env_dispatch.cpp +++ b/src/env_dispatch.cpp @@ -152,7 +152,7 @@ static void guess_emoji_width(const environment_t &vars) { if (auto width_str = vars.get(L"fish_emoji_width")) { int new_width = fish_wcstol(width_str->as_string().c_str()); g_fish_emoji_width = std::max(0, new_width); - debug(2, "'fish_emoji_width' preference: %d, overwriting default", g_fish_emoji_width); + FLOGF(term_support, "'fish_emoji_width' preference: %d, overwriting default", g_fish_emoji_width); return; } @@ -170,18 +170,18 @@ static void guess_emoji_width(const environment_t &vars) { if (term == L"Apple_Terminal" && version >= 400) { // Apple Terminal on High Sierra g_guessed_fish_emoji_width = 2; - debug(2, "default emoji width: 2 for %ls", term.c_str()); + FLOGF(term_support, "default emoji width: 2 for %ls", term.c_str()); } else if (term == L"iTerm.app") { // iTerm2 defaults to Unicode 8 sizes. // See https://gitlab.com/gnachman/iterm2/wikis/unicodeversionswitching g_guessed_fish_emoji_width = 1; - debug(2, "default emoji width: 1"); + FLOGF(term_support, "default emoji width: 1"); } else { // Default to whatever system wcwidth says to U+1F603, // but only if it's at least 1. int w = wcwidth(L'😃'); g_guessed_fish_emoji_width = w > 0 ? w : 1; - debug(2, "default emoji width: %d", g_guessed_fish_emoji_width); + FLOGF(term_support, "default emoji width: %d", g_guessed_fish_emoji_width); } } @@ -338,11 +338,11 @@ static void update_fish_color_support(const environment_t &vars) { if (auto fish_term256 = vars.get(L"fish_term256")) { // $fish_term256 support_term256 = bool_from_string(fish_term256->as_string()); - debug(2, L"256 color support determined by '$fish_term256'"); + FLOGF(term_support, L"256 color support determined by '$fish_term256'"); } else if (term.find(L"256color") != wcstring::npos) { // TERM is *256color*: 256 colors explicitly supported support_term256 = true; - debug(2, L"256 color support enabled for TERM=%ls", term.c_str()); + FLOGF(term_support, L"256 color support enabled for TERM=%ls", term.c_str()); } else if (term.find(L"xterm") != wcstring::npos) { // Assume that all 'xterm's can handle 256, except for Terminal.app from Snow Leopard wcstring term_program; @@ -352,23 +352,23 @@ static void update_fish_color_support(const environment_t &vars) { fish_wcstod(tpv->as_string().c_str(), nullptr) > 299) { // OS X Lion is version 299+, it has 256 color support (see github Wiki) support_term256 = true; - debug(2, L"256 color support enabled for TERM=%ls on Terminal.app", term.c_str()); + FLOGF(term_support, L"256 color support enabled for TERM=%ls on Terminal.app", term.c_str()); } else { support_term256 = true; - debug(2, L"256 color support enabled for TERM=%ls", term.c_str()); + FLOGF(term_support, L"256 color support enabled for TERM=%ls", term.c_str()); } } } else if (cur_term != nullptr) { // See if terminfo happens to identify 256 colors support_term256 = (max_colors >= 256); - debug(2, L"256 color support: %d colors per terminfo entry for %ls", max_colors, + FLOGF(term_support, L"256 color support: %d colors per terminfo entry for %ls", max_colors, term.c_str()); } // Handle $fish_term24bit if (auto fish_term24bit = vars.get(L"fish_term24bit")) { support_term24bit = bool_from_string(fish_term24bit->as_string()); - debug(2, L"'fish_term24bit' preference: 24-bit color %ls", + FLOGF(term_support, L"'fish_term24bit' preference: 24-bit color %ls", support_term24bit ? L"enabled" : L"disabled"); } else { // We don't attempt to infer term24 bit support yet. @@ -446,11 +446,11 @@ static void init_curses(const environment_t &vars) { std::string name = wcs2string(var_name); const auto var = vars.get(var_name, ENV_EXPORT); if (var.missing_or_empty()) { - debug(2, L"curses var %s missing or empty", name.c_str()); + FLOGF(term_support, L"curses var %s missing or empty", name.c_str()); unsetenv_lock(name.c_str()); } else { std::string value = wcs2string(var->as_string()); - debug(2, L"curses var %s='%s'", name.c_str(), value.c_str()); + FLOGF(term_support, L"curses var %s='%s'", name.c_str(), value.c_str()); setenv_lock(name.c_str(), value.c_str(), 1); } } diff --git a/src/flog.h b/src/flog.h index 7f61d2988..960d21d77 100644 --- a/src/flog.h +++ b/src/flog.h @@ -82,6 +82,8 @@ class category_list_t { category_t profile_history{L"profile-history", L"History performance measurements"}; category_t iothread{L"iothread", L"Background IO thread events"}; + + category_t term_support{L"term-support", L"Terminal feature detection"}; }; /// The class responsible for logging. From 14c2c623b4e4d63b0830bad0328725c69627fc3f Mon Sep 17 00:00:00 2001 From: Fabian Homborg Date: Sun, 19 Jan 2020 13:43:33 +0100 Subject: [PATCH 04/19] Add flog category for uvar file This used debug level 5, which means it was basically unusable. --- src/env_universal_common.cpp | 27 +++++++++++++-------------- src/flog.h | 2 ++ 2 files changed, 15 insertions(+), 14 deletions(-) diff --git a/src/env_universal_common.cpp b/src/env_universal_common.cpp index d8860cbd6..66155c178 100644 --- a/src/env_universal_common.cpp +++ b/src/env_universal_common.cpp @@ -382,7 +382,7 @@ void env_universal_t::load_from_fd(int fd, callback_data_list_t &callbacks) { // Get the dev / inode. const file_id_t current_file = file_id_for_fd(fd); if (current_file == last_read_file) { - debug(5, L"universal log sync elided based on fstat()"); + FLOGF(uvar_file, L"universal log sync elided based on fstat()"); } else { // Read a variables table from the file. var_table_t new_vars; @@ -409,14 +409,14 @@ bool env_universal_t::load_from_path(const std::string &path, callback_data_list // Check to see if the file is unchanged. We do this again in load_from_fd, but this avoids // opening the file unnecessarily. if (last_read_file != kInvalidFileID && file_id_for_path(path) == last_read_file) { - debug(5, L"universal log sync elided based on fast stat()"); + FLOGF(uvar_file, L"universal log sync elided based on fast stat()"); return true; } bool result = false; int fd = open_cloexec(path, O_RDONLY); if (fd >= 0) { - debug(5, L"universal log reading from file"); + FLOGF(uvar_file, L"universal log reading from file"); this->load_from_fd(fd, callbacks); close(fd); result = true; @@ -638,7 +638,7 @@ bool env_universal_t::open_and_acquire_lock(const std::string &path, int *out_fd // Returns true if modified variables were written, false if not. (There may still be variable // changes due to other processes on a false return). bool env_universal_t::sync(callback_data_list_t &callbacks) { - debug(5, L"universal log sync"); + FLOGF(uvar_file, L"universal log sync"); scoped_lock locker(lock); // Our saving strategy: // @@ -676,7 +676,7 @@ bool env_universal_t::sync(callback_data_list_t &callbacks) { // FIXME: Why don't we initialize()? auto def_vars_path = default_vars_path(); if (!def_vars_path) { - debug(2, L"No universal variable path available"); + FLOG(uvar_file, L"No universal variable path available"); return false; } explicit_vars_path = *def_vars_path; @@ -686,7 +686,7 @@ bool env_universal_t::sync(callback_data_list_t &callbacks) { // If we have no changes, just load. if (modified.empty()) { this->load_from_path(narrow_vars_path, callbacks); - debug(5, L"universal log no modifications"); + FLOGF(uvar_file, L"universal log no modifications"); return false; } @@ -694,12 +694,12 @@ bool env_universal_t::sync(callback_data_list_t &callbacks) { bool success = true; int vars_fd = -1; - debug(5, L"universal log performing full sync"); + FLOGF(uvar_file, L"universal log performing full sync"); // Open the file. if (success) { success = this->open_and_acquire_lock(narrow_vars_path, &vars_fd); - if (!success) debug(5, L"universal log open_and_acquire_lock() failed"); + if (!success) FLOGF(uvar_file, L"universal log open_and_acquire_lock() failed"); } // Read from it. @@ -730,13 +730,13 @@ bool env_universal_t::save(const wcstring &directory, const wcstring &vars_path) // Open adjacent temporary file. bool success = this->open_temporary_file(directory, &private_file_path, &private_fd); - if (!success) debug(5, L"universal log open_temporary_file() failed"); + if (!success) FLOGF(uvar_file, L"universal log open_temporary_file() failed"); // Write to it. if (success) { assert(private_fd >= 0); success = this->write_to_fd(private_fd, private_file_path); - if (!success) debug(5, L"universal log write_to_fd() failed"); + if (!success) FLOGF(uvar_file, L"universal log write_to_fd() failed"); } if (success) { @@ -744,8 +744,8 @@ bool env_universal_t::save(const wcstring &directory, const wcstring &vars_path) struct stat sbuf; if (wstat(vars_path, &sbuf) >= 0) { if (fchown(private_fd, sbuf.st_uid, sbuf.st_gid) == -1) - debug(5, L"universal log fchown() failed"); - if (fchmod(private_fd, sbuf.st_mode) == -1) debug(5, L"universal log fchmod() failed"); + FLOGF(uvar_file, L"universal log fchown() failed"); + if (fchmod(private_fd, sbuf.st_mode) == -1) FLOGF(uvar_file, L"universal log fchmod() failed"); } // Linux by default stores the mtime with low precision, low enough that updates that occur @@ -766,7 +766,7 @@ bool env_universal_t::save(const wcstring &directory, const wcstring &vars_path) // Apply new file. success = this->move_new_vars_file_into_place(private_file_path, vars_path); - if (!success) debug(5, L"universal log move_new_vars_file_into_place() failed"); + if (!success) FLOGF(uvar_file, L"universal log move_new_vars_file_into_place() failed"); } if (success) { @@ -933,7 +933,6 @@ void env_universal_t::parse_message_2x_internal(const wcstring &msgstr, var_tabl const wchar_t *const msg = msgstr.c_str(); const wchar_t *cursor = msg; - // debug(3, L"parse_message( %ls );", msg); if (cursor[0] == L'#') return; env_var_t::env_var_flags_t flags = 0; diff --git a/src/flog.h b/src/flog.h index 960d21d77..88ade97df 100644 --- a/src/flog.h +++ b/src/flog.h @@ -74,6 +74,8 @@ class category_list_t { category_t env_export{L"env-export", L"Changes to exported variables"}; + category_t uvar_file{L"uvar-file", L"Writing/reading the universal variable store"}; + category_t topic_monitor{L"topic-monitor", L"Internal details of the topic monitor"}; category_t char_encoding{L"char-encoding", L"Character encoding issues"}; From 6793d3534040d66a0125208544559657f646360c Mon Sep 17 00:00:00 2001 From: Fabian Homborg Date: Sun, 19 Jan 2020 13:47:37 +0100 Subject: [PATCH 05/19] Add flog categories for parse-productions One for usable messages, another for the chatty ones. Use like `--debug=parse-productions'*'`. --- src/flog.h | 3 +++ src/parse_productions.cpp | 4 ++-- 2 files changed, 5 insertions(+), 2 deletions(-) diff --git a/src/flog.h b/src/flog.h index 88ade97df..bd0bc3b3b 100644 --- a/src/flog.h +++ b/src/flog.h @@ -59,6 +59,9 @@ class category_list_t { category_t exec_fork{L"exec-fork", L"Calls to fork()"}; + category_t parse_productions{L"parse-productions", L"Resolving tokens"}; + category_t parse_productions_chatty{L"parse-productions-chatty", L"Resolving tokens (chatty messages)"}; + 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"}; diff --git a/src/parse_productions.cpp b/src/parse_productions.cpp index 9584ee096..905d67108 100644 --- a/src/parse_productions.cpp +++ b/src/parse_productions.cpp @@ -414,7 +414,7 @@ const production_element_t *parse_productions::production_for_token(parse_token_ const parse_token_t &input2, parse_node_tag_t *out_tag) { // this is **extremely** chatty - debug(6, L"Resolving production for %ls with input token <%ls>", + FLOGF(parse_productions_chatty, L"Resolving production for %ls with input token <%ls>", token_type_description(node_type), input1.describe().c_str()); // Fetch the function to resolve the list of productions. @@ -462,7 +462,7 @@ const production_element_t *parse_productions::production_for_token(parse_token_ const production_element_t *result = resolver(input1, input2, out_tag); if (result == nullptr) { - debug(5, L"Node type '%ls' has no production for input '%ls' (in %s)", + FLOGF(parse_productions, L"Node type '%ls' has no production for input '%ls' (in %s)", token_type_description(node_type), input1.describe().c_str(), __FUNCTION__); } From 123676075f4f4534ac99cd4e43317c1b6f27c897 Mon Sep 17 00:00:00 2001 From: Fabian Homborg Date: Sun, 19 Jan 2020 13:49:56 +0100 Subject: [PATCH 06/19] Add flog category for history *file* --- src/flog.h | 1 + src/history.cpp | 12 ++++++------ 2 files changed, 7 insertions(+), 6 deletions(-) diff --git a/src/flog.h b/src/flog.h index bd0bc3b3b..52be62a56 100644 --- a/src/flog.h +++ b/src/flog.h @@ -83,6 +83,7 @@ class category_list_t { category_t char_encoding{L"char-encoding", L"Character encoding issues"}; category_t history{L"history", L"Command history events"}; + category_t history_file{L"history-file", L"Reading/Writing the history file"}; category_t profile_history{L"profile-history", L"History performance measurements"}; diff --git a/src/history.cpp b/src/history.cpp index 89fbd199f..d9e1600bf 100644 --- a/src/history.cpp +++ b/src/history.cpp @@ -718,7 +718,7 @@ bool history_impl_t::rewrite_to_temporary_file(int existing_fd, int dst_fd) cons err = flush_to_fd(&buffer, dst_fd, 0); } if (err) { - debug(2, L"Error %d when writing to temporary history file", err); + FLOGF(history_file, L"Error %d when writing to temporary history file", err); } return err == 0; @@ -790,7 +790,7 @@ bool history_impl_t::save_internal_via_rewrite() { // The file has changed, so we're going to re-read it // Truncate our tmp_fd so we can reuse it if (ftruncate(tmp_fd, 0) == -1 || lseek(tmp_fd, 0, SEEK_SET) == -1) { - debug(2, L"Error %d when truncating temporary history file", errno); + FLOGF(history_file, L"Error %d when truncating temporary history file", errno); } } else { // The file is unchanged, or the new file doesn't exist or we can't read it @@ -804,16 +804,16 @@ bool history_impl_t::save_internal_via_rewrite() { struct stat sbuf; if (target_fd_after.valid() && fstat(target_fd_after.fd(), &sbuf) >= 0) { if (fchown(tmp_fd, sbuf.st_uid, sbuf.st_gid) == -1) { - debug(2, L"Error %d when changing ownership of history file", errno); + FLOGF(history_file, L"Error %d when changing ownership of history file", errno); } if (fchmod(tmp_fd, sbuf.st_mode) == -1) { - debug(2, L"Error %d when changing mode of history file", errno); + FLOGF(history_file, L"Error %d when changing mode of history file", errno); } } // Slide it into place if (wrename(tmp_name, *target_name) == -1) { - debug(2, L"Error %d when renaming history file", errno); + FLOGF(history_file, L"Error %d when renaming history file", errno); } // We did it @@ -1081,7 +1081,7 @@ void history_impl_t::populate_from_config_path() { ssize_t written = write(dst_fd.fd(), buf, static_cast(size)); if (written < 0) { // This message does not have high enough priority to be shown by default. - debug(2, L"Error when writing history file"); + FLOGF(history_file, L"Error when writing history file"); break; } } From 5da4f7e7c5e2c11b3aac1a8f14d5368bd6c2474a Mon Sep 17 00:00:00 2001 From: Fabian Homborg Date: Sun, 19 Jan 2020 13:53:23 +0100 Subject: [PATCH 07/19] Add flog category for config reading --- src/fish.cpp | 14 +++++++------- src/flog.h | 2 ++ 2 files changed, 9 insertions(+), 7 deletions(-) diff --git a/src/fish.cpp b/src/fish.cpp index 72965610f..7db3ade1d 100644 --- a/src/fish.cpp +++ b/src/fish.cpp @@ -136,13 +136,13 @@ static struct config_paths_t determine_config_directory_paths(const char *argv0) bool done = false; std::string exec_path = get_executable_path(argv0); if (get_realpath(exec_path)) { - debug(2, L"exec_path: '%s', argv[0]: '%s'", exec_path.c_str(), argv0); + FLOGF(config, L"exec_path: '%s', argv[0]: '%s'", exec_path.c_str(), argv0); // TODO: we should determine program_name from argv0 somewhere in this file #ifdef CMAKE_BINARY_DIR // Detect if we're running right out of the CMAKE build directory if (string_prefixes_string(CMAKE_BINARY_DIR, exec_path.c_str())) { - debug(2, + FLOGF(config, "Running out of build directory, using paths relative to CMAKE_SOURCE_DIR:\n %s", CMAKE_SOURCE_DIR); @@ -163,7 +163,7 @@ static struct config_paths_t determine_config_directory_paths(const char *argv0) if (has_suffix(exec_path, installed_suffix, false)) { suffix = installed_suffix; } else if (has_suffix(exec_path, just_a_fish, false)) { - debug(2, L"'fish' not in a 'bin/', trying paths relative to source tree"); + FLOGF(config, L"'fish' not in a 'bin/', trying paths relative to source tree"); suffix = just_a_fish; } @@ -194,14 +194,14 @@ static struct config_paths_t determine_config_directory_paths(const char *argv0) if (!done) { // Fall back to what got compiled in. - debug(2, L"Using compiled in paths:"); + FLOGF(config, L"Using compiled in paths:"); paths.data = L"" DATADIR "/fish"; paths.sysconf = L"" SYSCONFDIR "/fish"; paths.doc = L"" DOCDIR; paths.bin = L"" BINDIR; } - debug(2, + FLOGF(config, L"determine_config_directory_paths() results:\npaths.data: %ls\npaths.sysconf: " L"%ls\npaths.doc: %ls\npaths.bin: %ls", paths.data.c_str(), paths.sysconf.c_str(), paths.doc.c_str(), paths.bin.c_str()); @@ -221,10 +221,10 @@ static void source_config_in_directory(const wcstring &dir) { const wcstring escaped_dir = escape_string(dir, ESCAPE_ALL); const wcstring escaped_pathname = escaped_dir + L"/config.fish"; if (waccess(config_pathname, R_OK) != 0) { - debug(2, L"not sourcing %ls (not readable or does not exist)", escaped_pathname.c_str()); + FLOGF(config, L"not sourcing %ls (not readable or does not exist)", escaped_pathname.c_str()); return; } - debug(2, L"sourcing %ls", escaped_pathname.c_str()); + FLOGF(config, L"sourcing %ls", escaped_pathname.c_str()); const wcstring cmd = L"builtin source " + escaped_pathname; parser_t &parser = parser_t::principal_parser(); diff --git a/src/flog.h b/src/flog.h index 52be62a56..178016af7 100644 --- a/src/flog.h +++ b/src/flog.h @@ -53,6 +53,8 @@ class category_list_t { category_t warning{L"warning", L"Warnings (on by default)", true}; + category_t config{L"config", L"Finding and reading configuration"}; + 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"}; From b09ae82ecf6e84f087d28cce28bb7f360b6c7731 Mon Sep 17 00:00:00 2001 From: Fabian Homborg Date: Sun, 19 Jan 2020 13:54:00 +0100 Subject: [PATCH 08/19] Remove a few less useful debug messages These were level 5, so I'd bet nobody ever saw them --- src/intern.cpp | 1 - src/path.cpp | 2 -- 2 files changed, 3 deletions(-) diff --git a/src/intern.cpp b/src/intern.cpp index 53dc61214..07d1d5561 100644 --- a/src/intern.cpp +++ b/src/intern.cpp @@ -21,7 +21,6 @@ owning_lock> string_table; static const wchar_t *intern_with_dup(const wchar_t *in, bool dup) { if (!in) return nullptr; - debug(5, L"intern %ls", in); auto table = string_table.acquire(); const wchar_t *result; diff --git a/src/path.cpp b/src/path.cpp index a6271adaa..f4b778249 100644 --- a/src/path.cpp +++ b/src/path.cpp @@ -35,8 +35,6 @@ const wcstring_list_t dflt_pathsv({L"/bin", L"/usr/bin", PREFIX L"/bin"}); static bool path_get_path_core(const wcstring &cmd, wcstring *out_path, const maybe_t &bin_path_var) { - debug(5, L"path_get_path( '%ls' )", cmd.c_str()); - // If the command has a slash, it must be an absolute or relative path and thus we don't bother // looking for a matching command. if (cmd.find(L'/') != wcstring::npos) { From 349b9e9dee0f41f03140aaf3a00673ec728e366c Mon Sep 17 00:00:00 2001 From: Fabian Homborg Date: Sun, 19 Jan 2020 13:55:03 +0100 Subject: [PATCH 09/19] Remove commented out debugs --- src/event.cpp | 2 -- src/exec.cpp | 1 - src/expand.cpp | 7 ------- src/highlight.cpp | 2 -- src/postfork.cpp | 3 --- 5 files changed, 15 deletions(-) diff --git a/src/event.cpp b/src/event.cpp index f3bae6d13..e20d4567e 100644 --- a/src/event.cpp +++ b/src/event.cpp @@ -278,8 +278,6 @@ static void event_fire_internal(parser_t &parser, const event_t &event) { buffer.append(escape_string(arg, ESCAPE_ALL)); } - // debug( 1, L"Event handler fires command '%ls'", buffer.c_str() ); - // Event handlers are not part of the main flow of code, so they are marked as // non-interactive. scoped_push interactive{&ld.is_interactive, false}; diff --git a/src/exec.cpp b/src/exec.cpp index 026bfa4ef..06b7237c0 100644 --- a/src/exec.cpp +++ b/src/exec.cpp @@ -107,7 +107,6 @@ static void safe_launch_process(process_t *p, const char *actual_cmd, const char const char *const *cenvv) { UNUSED(p); int err; - // debug( 1, L"exec '%ls'", p->argv[0] ); // This function never returns, so we take certain liberties with constness. char *const *envv = const_cast(cenvv); diff --git a/src/expand.cpp b/src/expand.cpp index e76227e10..03bb97e69 100644 --- a/src/expand.cpp +++ b/src/expand.cpp @@ -194,7 +194,6 @@ static size_t parse_slice(const wchar_t *in, wchar_t **end_ptr, std::vector 0) { return pos; } - // debug( 0, L"Push idx %d", tmp ); long i1 = tmp > -1 ? tmp : size + tmp + 1; pos = end - in; @@ -210,7 +209,6 @@ static size_t parse_slice(const wchar_t *in, wchar_t **end_ptr, std::vector -1 ? tmp1 : size + tmp1 + 1; // Skip sequences that are entirely outside. // This means "17..18" expands to nothing if there are less than 17 elements. @@ -229,7 +227,6 @@ static size_t parse_slice(const wchar_t *in, wchar_t **end_ptr, std::vector %ls ->%ls", path, tilde, unescaped ); - for (auto c : path_with_magic) { switch (c) { case PROCESS_EXPAND_SELF: diff --git a/src/postfork.cpp b/src/postfork.cpp index dcdb78a08..c3e0a77b2 100644 --- a/src/postfork.cpp +++ b/src/postfork.cpp @@ -374,9 +374,6 @@ void safe_report_exec_error(int err, const char *actual_cmd, const char *const * default: { const char *err = safe_strerror(errno); debug_safe(0, "exec: %s", err); - - // FLOGF(error, L"The file '%ls' is marked as an executable but could not be run by the - // operating system.", p->actual_cmd); break; } } From a48926dee55b18b91744282cb8f0fac9246b7f7f Mon Sep 17 00:00:00 2001 From: Fabian Homborg Date: Sun, 19 Jan 2020 14:19:34 +0100 Subject: [PATCH 10/19] Add and use "should_flog" macro Useful to figure out if a flog category is enabled. We only use it in one place, but it seems like the sort of thing that should exist. --- src/flog.h | 3 +++ src/io.cpp | 2 +- 2 files changed, 4 insertions(+), 1 deletion(-) diff --git a/src/flog.h b/src/flog.h index 178016af7..5a4acf5a2 100644 --- a/src/flog.h +++ b/src/flog.h @@ -182,3 +182,6 @@ void log_extra_to_flog_file(const wcstring &s); } while (0) #endif + +#define should_flog(wht) \ + (flog_details::category_list_t::g_instance->wht.enabled) diff --git a/src/io.cpp b/src/io.cpp index ed241237b..afdc8ec0a 100644 --- a/src/io.cpp +++ b/src/io.cpp @@ -257,7 +257,7 @@ bool io_chain_t::append_from_specs(const redirection_spec_list_t &specs, const w FLOGF(warning, NOCLOB_ERROR, spec.target.c_str()); } else { FLOGF(warning, FILE_ERROR, spec.target.c_str()); - if (should_debug(1)) wperror(L"open"); + if (should_flog(warning)) wperror(L"open"); } return false; } From 8b1ac0912ba0f1572427a088db976f9c9287cefa Mon Sep 17 00:00:00 2001 From: Fabian Homborg Date: Sun, 19 Jan 2020 14:27:23 +0100 Subject: [PATCH 11/19] Add reader flog category For both input and reader, because the "reader" term is more general and we don't have enough messages to justify multiple categories --- src/flog.h | 2 ++ src/input.cpp | 2 +- src/input_common.cpp | 3 ++- src/reader.cpp | 2 +- 4 files changed, 6 insertions(+), 3 deletions(-) diff --git a/src/flog.h b/src/flog.h index 5a4acf5a2..111f0476e 100644 --- a/src/flog.h +++ b/src/flog.h @@ -92,6 +92,8 @@ class category_list_t { category_t iothread{L"iothread", L"Background IO thread events"}; category_t term_support{L"term-support", L"Terminal feature detection"}; + + category_t reader{L"reader", L"The interactive reader/input system"}; }; /// The class responsible for logging. diff --git a/src/input.cpp b/src/input.cpp index e2600656d..df0322bbf 100644 --- a/src/input.cpp +++ b/src/input.cpp @@ -458,7 +458,7 @@ void inputter_t::mapping_execute_matching_or_generic(bool allow_commands) { if (auto mapping = find_mapping()) { mapping_execute(*mapping, allow_commands); } else { - debug(2, L"no generic found, ignoring char..."); + FLOGF(reader, L"no generic found, ignoring char..."); auto evt = event_queue_.readch(); if (evt.is_eof()) { event_queue_.push_front(evt); diff --git a/src/input_common.cpp b/src/input_common.cpp index 4767a0be0..a7897008f 100644 --- a/src/input_common.cpp +++ b/src/input_common.cpp @@ -24,6 +24,7 @@ #include "env.h" #include "env_universal_common.h" #include "fallback.h" // IWYU pragma: keep +#include "flog.h" #include "global_safety.h" #include "input_common.h" #include "iothread.h" @@ -188,7 +189,7 @@ char_event_t input_event_queue_t::readch() { switch (sz) { case static_cast(-1): { std::memset(&state, '\0', sizeof(state)); - debug(2, L"Illegal input"); + FLOG(reader, L"Illegal input"); return char_event_type_t::check_exit; } case static_cast(-2): { diff --git a/src/reader.cpp b/src/reader.cpp index a7b0468ff..ecd38b263 100644 --- a/src/reader.cpp +++ b/src/reader.cpp @@ -3311,7 +3311,7 @@ maybe_t reader_data_t::readline(int nchars_or_0) { } else { // This can happen if the user presses a control char we don't recognize. No // reason to report this to the user unless they've enabled debugging output. - debug(2, _(L"Unknown key binding 0x%X"), c); + FLOGF(reader, _(L"Unknown key binding 0x%X"), c); } rls.last_cmd = none(); } From fe931aeea70d05c36de687540672943858ed5d8d Mon Sep 17 00:00:00 2001 From: Fabian Homborg Date: Sun, 19 Jan 2020 14:27:55 +0100 Subject: [PATCH 12/19] Add more messages to termowner flog category --- src/proc.cpp | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/proc.cpp b/src/proc.cpp index c018dbae1..03ce28c47 100644 --- a/src/proc.cpp +++ b/src/proc.cpp @@ -736,7 +736,7 @@ int terminal_maybe_give_to_job(const job_t *j, bool continuing_from_stopped) { } else { // Debug the original tcsetpgrp error (not the waitpid errno) to the log, and // then retry until not EPERM or the process group has exited. - debug(2, L"terminal_give_to_job(): EPERM.\n", j->pgid); + FLOGF(proc_termowner, L"terminal_give_to_job(): EPERM.\n", j->pgid); continue; } } else { @@ -755,7 +755,7 @@ int terminal_maybe_give_to_job(const job_t *j, bool continuing_from_stopped) { // job/group have been started, the only way this can happen is if the very last // process in the group terminated and didn't need to access the terminal, otherwise // it would have hung waiting for terminal IO (SIGTTIN). We can safely ignore this. - debug(3, L"tcsetpgrp called but process group %d has terminated.\n", j->pgid); + FLOGF(proc_termowner, L"tcsetpgrp called but process group %d has terminated.\n", j->pgid); return notneeded; } From 0c49f4502826edae29ba7c1ceb9aa0f074979871 Mon Sep 17 00:00:00 2001 From: Fabian Homborg Date: Sun, 19 Jan 2020 14:29:56 +0100 Subject: [PATCH 13/19] fish_key_reader: Remove debug messages These are related to *signal handlers* in fish_key_reader, and I don't think this code needed to be touched since it was added. --- src/fish_key_reader.cpp | 7 ------- 1 file changed, 7 deletions(-) diff --git a/src/fish_key_reader.cpp b/src/fish_key_reader.cpp index 8f6a04969..1e0f90c84 100644 --- a/src/fish_key_reader.cpp +++ b/src/fish_key_reader.cpp @@ -274,13 +274,6 @@ static void install_our_signal_handlers() { for (int signo = 1; signo < 32; signo++) { if (sigaction(signo, &new_sa, &old_sa) != -1) { std::memcpy(&old_sigactions[signo], &old_sa, sizeof(old_sa)); - if (old_sa.sa_handler == SIG_IGN) { - debug(3, "signal #%d (%ls) was being ignored", signo, sig2wcs(signo)); - } - if (old_sa.sa_flags && ~SA_SIGINFO != 0) { - debug(3, L"signal #%d (%ls) handler had flags 0x%X", signo, sig2wcs(signo), - old_sa.sa_flags); - } } } } From 246882b52d1d4b645266cbfbf61cbd9c5f7813ec Mon Sep 17 00:00:00 2001 From: Fabian Homborg Date: Sun, 19 Jan 2020 14:32:41 +0100 Subject: [PATCH 14/19] Add proc-pgroup flog category I'm not *super*-happy with this, because pgroups and terminal ownership and such are quite entertwined. But hey, if all fails just use `proc'*'` --- src/flog.h | 1 + src/postfork.cpp | 2 +- src/proc.cpp | 4 ++-- 3 files changed, 4 insertions(+), 3 deletions(-) diff --git a/src/flog.h b/src/flog.h index 111f0476e..cba1d4aac 100644 --- a/src/flog.h +++ b/src/flog.h @@ -74,6 +74,7 @@ class category_list_t { L"Reaping internal (non-forked) processes"}; category_t proc_reap_external{L"proc-reap-external", L"Reaping external (forked) processes"}; + category_t proc_pgroup{L"proc-pgroup", L"Process groups"}; category_t env_locale{L"env-locale", L"Changes to locale variables"}; diff --git a/src/postfork.cpp b/src/postfork.cpp index c3e0a77b2..4dfad691f 100644 --- a/src/postfork.cpp +++ b/src/postfork.cpp @@ -124,7 +124,7 @@ bool set_child_group(job_t *j, pid_t child_pid) { // ever leads to a terminal hang due if both this setpgid call AND posix_spawn's // internal setpgid calls failed), write to the debug log so a future developer // doesn't go crazy trying to track this down. - debug(2, "Error %d while calling setpgid for child %d (probably harmless)", errno, + FLOGF(proc_pgroup, "Error %d while calling setpgid for child %d (probably harmless)", errno, child_pid); } } diff --git a/src/proc.cpp b/src/proc.cpp index 03ce28c47..324ea3fa4 100644 --- a/src/proc.cpp +++ b/src/proc.cpp @@ -798,7 +798,7 @@ pid_t terminal_acquire_before_builtin(int job_pgid) { static bool terminal_return_from_job(job_t *j, int restore_attrs) { errno = 0; if (j->pgid == 0) { - debug(2, "terminal_return_from_job() returning early due to no process group"); + FLOG(proc_pgroup, "terminal_return_from_job() returning early due to no process group"); return true; } @@ -868,7 +868,7 @@ void job_t::continue_job(parser_t &parser, bool reclaim_foreground_pgrp, bool se // signal individually. job_t::signal() does the same, but uses the shell's own pgroup // to make that distinction. if (!signal(SIGCONT)) { - debug(2, "Failed to send SIGCONT to any processes in pgroup %d!", pgid); + FLOGF(proc_pgroup, "Failed to send SIGCONT to any processes in pgroup %d!", pgid); // This returns without bubbling up the error. Presumably that is OK. return; } From 483018222db22242d4bdb17eeee7659a190cb64a Mon Sep 17 00:00:00 2001 From: Fabian Homborg Date: Sun, 19 Jan 2020 14:39:17 +0100 Subject: [PATCH 15/19] Add complete flog category --- src/complete.cpp | 6 +++--- src/flog.h | 1 + 2 files changed, 4 insertions(+), 3 deletions(-) diff --git a/src/complete.cpp b/src/complete.cpp index 67d1522d2..696023b2c 100644 --- a/src/complete.cpp +++ b/src/complete.cpp @@ -913,7 +913,7 @@ bool completer_t::complete_param(const wcstring &cmd_orig, const wcstring &popt, // This prevents errors caused during the execution of completion providers for // tools that do not exist. Applies to both manual completions ("cm", "cmd ") // and automatic completions ("gi" autosuggestion provider -> git) - debug(4, "Skipping completions for non-existent head\n"); + FLOG(complete, "Skipping completions for non-existent head"); } else { run_on_main_thread([&]() { complete_load(cmd); }); } @@ -1134,7 +1134,7 @@ void completer_t::complete_param_expand(const wcstring &str, bool do_file, const wcstring sep_string = wcstring(str, sep_index + 1); completion_list_t local_completions; if (expand_string(sep_string, &local_completions, flags, ctx) == expand_result_t::error) { - debug(3, L"Error while expanding string '%ls'", sep_string.c_str()); + FLOGF(complete, L"Error while expanding string '%ls'", sep_string.c_str()); } // Any COMPLETE_REPLACES_TOKEN will also stomp the separator. We need to "repair" them by @@ -1153,7 +1153,7 @@ void completer_t::complete_param_expand(const wcstring &str, bool do_file, if (string_prefixes_string(L"-", str)) flags.clear(expand_flag::fuzzy_match); if (expand_string(str, &this->completions, flags, ctx) == expand_result_t::error) { - debug(3, L"Error while expanding string '%ls'", str.c_str()); + FLOGF(complete, L"Error while expanding string '%ls'", str.c_str()); } } } diff --git a/src/flog.h b/src/flog.h index cba1d4aac..aa2574e37 100644 --- a/src/flog.h +++ b/src/flog.h @@ -95,6 +95,7 @@ class category_list_t { category_t term_support{L"term-support", L"Terminal feature detection"}; category_t reader{L"reader", L"The interactive reader/input system"}; + category_t complete{L"complete", L"The completion system"}; }; /// The class responsible for logging. From 4cb3ce03143cdff12da478840eaabbd0919a43fe Mon Sep 17 00:00:00 2001 From: Fabian Homborg Date: Sun, 19 Jan 2020 14:41:17 +0100 Subject: [PATCH 16/19] Add a 5 debug to the iothread flog --- src/iothread.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/iothread.cpp b/src/iothread.cpp index 5f40fe5bc..374d7e855 100644 --- a/src/iothread.cpp +++ b/src/iothread.cpp @@ -449,7 +449,7 @@ bool make_detached_pthread(void *(*func)(void *), void *param) { int err = pthread_create(&thread, nullptr, func, param); if (err == 0) { // Success, return the thread. - debug(5, "pthread %p spawned", (void *)(intptr_t)thread); + FLOGF(iothread, "pthread %p spawned", (void *)(intptr_t)thread); DIE_ON_FAILURE(pthread_detach(thread)); } else { perror("pthread_create"); From f632a9e9989fa933c4410ac34e8d00a96322c9fd Mon Sep 17 00:00:00 2001 From: Fabian Homborg Date: Sun, 19 Jan 2020 14:42:12 +0100 Subject: [PATCH 17/19] Add env-dispatch flog category --- src/env_dispatch.cpp | 2 +- src/flog.h | 2 ++ 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/src/env_dispatch.cpp b/src/env_dispatch.cpp index 25927e2c5..6b43dd2d8 100644 --- a/src/env_dispatch.cpp +++ b/src/env_dispatch.cpp @@ -135,7 +135,7 @@ void env_dispatch_init(const environment_t &vars) { /// Properly sets all timezone information. static void handle_timezone(const wchar_t *env_var_name, const environment_t &vars) { const auto var = vars.get(env_var_name, ENV_DEFAULT); - debug(2, L"handle_timezone() current timezone var: |%ls| => |%ls|", env_var_name, + FLOGF(env_dispatch, L"handle_timezone() current timezone var: |%ls| => |%ls|", env_var_name, !var ? L"MISSING" : var->as_string().c_str()); const std::string &name = wcs2string(env_var_name); if (var.missing_or_empty()) { diff --git a/src/flog.h b/src/flog.h index aa2574e37..7fa7421c9 100644 --- a/src/flog.h +++ b/src/flog.h @@ -80,6 +80,8 @@ class category_list_t { category_t env_export{L"env-export", L"Changes to exported variables"}; + category_t env_dispatch{L"env-dispatch", L"Reacting to variables"}; + category_t uvar_file{L"uvar-file", L"Writing/reading the universal variable store"}; category_t topic_monitor{L"topic-monitor", L"Internal details of the topic monitor"}; From 26fa774f44cf4efb5f1d11450869009527e2f112 Mon Sep 17 00:00:00 2001 From: Fabian Homborg Date: Sun, 19 Jan 2020 14:44:30 +0100 Subject: [PATCH 18/19] Add path flog category --- src/flog.h | 1 + src/path.cpp | 2 +- 2 files changed, 2 insertions(+), 1 deletion(-) diff --git a/src/flog.h b/src/flog.h index 7fa7421c9..ed9988cb8 100644 --- a/src/flog.h +++ b/src/flog.h @@ -98,6 +98,7 @@ class category_list_t { category_t reader{L"reader", L"The interactive reader/input system"}; category_t complete{L"complete", L"The completion system"}; + category_t path{L"path", L"Searching/using paths"}; }; /// The class responsible for logging. diff --git a/src/path.cpp b/src/path.cpp index f4b778249..cc5e87618 100644 --- a/src/path.cpp +++ b/src/path.cpp @@ -122,7 +122,7 @@ bool path_get_path(const wcstring &cmd, wcstring *out_path, const environment_t } wcstring_list_t path_get_paths(const wcstring &cmd, const environment_t &vars) { - debug(3, L"path_get_paths('%ls')", cmd.c_str()); + FLOGF(path, L"path_get_paths('%ls')", cmd.c_str()); wcstring_list_t paths; // If the command has a slash, it must be an absolute or relative path and thus we don't bother From 65397d4f5efd74e09dd59f574ac3acb87f1fc755 Mon Sep 17 00:00:00 2001 From: Fabian Homborg Date: Sun, 19 Jan 2020 15:07:06 +0100 Subject: [PATCH 19/19] Fix tests By changing to flog I inadvertently changed the warning text from " fish:" to "warning:". Since that's also okay, let's leave it. --- tests/checks/directory-redirect.fish | 2 +- tests/test_exec_fail.err | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/tests/checks/directory-redirect.fish b/tests/checks/directory-redirect.fish index 003bb7666..b3219b6fb 100644 --- a/tests/checks/directory-redirect.fish +++ b/tests/checks/directory-redirect.fish @@ -3,7 +3,7 @@ begin end >. status -b; and echo "status -b returned true after bad redirect on a begin block" # Note that we sometimes get fancy quotation marks here, so let's match three characters -#CHECKERR: fish: An error occurred while redirecting file {{...}} +#CHECKERR: warning: An error occurred while redirecting file {{...}} #CHECKERR: {{open: Is a directory|open: Invalid argument}} echo $status #CHECK: 1 diff --git a/tests/test_exec_fail.err b/tests/test_exec_fail.err index 6a3453fce..e2c8dd99f 100644 --- a/tests/test_exec_fail.err +++ b/tests/test_exec_fail.err @@ -1,4 +1,4 @@ - fish: An error occurred while redirecting file 'nosuchfile' +warning: An error occurred while redirecting file 'nosuchfile' open: No such file or directory - fish: An error occurred while redirecting file 'nosuchfile' +warning: An error occurred while redirecting file 'nosuchfile' open: No such file or directory