Migrate remaining calls from debug_safe to FLOGF_SAFE

This removes debug_level and remaining debug bits.

We also simplify some of the exec errors, reducing them to a single
line.
This commit is contained in:
ridiculousfish 2021-07-05 14:29:24 -07:00
parent 28bf44d698
commit b395b33776
8 changed files with 43 additions and 155 deletions

View File

@ -87,8 +87,8 @@ static relaxed_atomic_t<wchar_t> obfuscation_read_char;
wchar_t get_obfuscation_read_char() { return obfuscation_read_char; }
bool g_profiling_active = false;
const wchar_t *program_name;
std::atomic<int> debug_level{1}; // default maximum debug output level (errors and warnings)
/// Be able to restore the term's foreground process group.
/// This is set during startup and not modified after.
@ -608,48 +608,6 @@ static void debug_shared(const wchar_t level, const wcstring &msg) {
}
}
void debug_safe(int level, const char *msg, const char *param1, const char *param2,
const char *param3, const char *param4, const char *param5, const char *param6,
const char *param7, const char *param8, const char *param9, const char *param10,
const char *param11, const char *param12) {
const char *const params[] = {param1, param2, param3, param4, param5, param6,
param7, param8, param9, param10, param11, param12};
if (!msg) return;
// Can't call fwprintf, that may allocate memory Just call write() over and over.
if (level > debug_level) return;
int errno_old = errno;
size_t param_idx = 0;
const char *cursor = msg;
while (*cursor != '\0') {
const char *end = std::strchr(cursor, '%');
if (end == nullptr) end = cursor + std::strlen(cursor);
ignore_result(write(STDERR_FILENO, cursor, end - cursor));
if (end[0] == '%' && end[1] == 's') {
// Handle a format string.
assert(param_idx < sizeof params / sizeof *params);
const char *format = params[param_idx++];
if (!format) format = "(null)";
ignore_result(write(STDERR_FILENO, format, std::strlen(format)));
cursor = end + 2;
} else if (end[0] == '\0') {
// Must be at the end of the string.
cursor = end;
} else {
// Some other format specifier, just skip it.
cursor = end + 1;
}
}
// We always append a newline.
ignore_result(write(STDERR_FILENO, "\n", 1));
errno = errno_old;
}
// Careful to not negate LLONG_MIN.
static unsigned long long absolute_value(long long x) {
if (x >= 0) return static_cast<unsigned long long>(x);

View File

@ -163,31 +163,6 @@ using job_id_t = int;
/// Every job has a unique positive value for this.
using internal_job_id_t = uint64_t;
/// Issue a debug message with printf-style string formating and automatic line breaking. The string
/// will begin with the string \c program_name, followed by a colon and a whitespace.
///
/// Because debug is often called to tell the user about an error, before using wperror to give a
/// specific error message, debug will never ever modify the value of errno.
///
/// \param level the priority of the message. Lower number means higher priority. Messages with a
/// priority_number higher than \c debug_level will be ignored..
/// \param msg the message format string.
///
/// Example:
///
/// <code>debug( 1, L"Pi = %.3f", M_PI );</code>
///
/// will print the string 'fish: Pi = 3.141', given that debug_level is 1 or higher, and that
/// program_name is 'fish'.
[[gnu::noinline, gnu::format(printf, 2, 3)]] void debug_impl(int level, const char *msg, ...);
[[gnu::noinline]] void debug_impl(int level, const wchar_t *msg, ...);
/// The verbosity level of fish. If a call to debug has a severity level higher than \c debug_level,
/// it will not be printed.
extern std::atomic<int> debug_level;
inline bool should_debug(int level) { return level <= debug_level.load(std::memory_order_relaxed); }
/// Exits without invoking destructors (via _exit), useful for code after fork.
[[noreturn]] void exit_without_destructors(int code);
@ -340,16 +315,6 @@ wcstring format_size(long long sz);
/// Version of format_size that does not allocate memory.
void format_size_safe(char buff[128], unsigned long long sz);
/// Our crappier versions of debug which is guaranteed to not allocate any memory, or do anything
/// other than call write(). This is useful after a call to fork() with threads.
void debug_safe(int level, const char *msg, const char *param1 = nullptr,
const char *param2 = nullptr, const char *param3 = nullptr,
const char *param4 = nullptr, const char *param5 = nullptr,
const char *param6 = nullptr, const char *param7 = nullptr,
const char *param8 = nullptr, const char *param9 = nullptr,
const char *param10 = nullptr, const char *param11 = nullptr,
const char *param12 = nullptr);
/// Writes out a long safely.
void format_long_safe(char buff[64], long val);
void format_long_safe(wchar_t buff[64], long val);

View File

@ -296,17 +296,7 @@ static int fish_parse_opt(int argc, char **argv, fish_cmd_opts_t *opts) {
break;
}
case 'd': {
char *end;
long tmp;
errno = 0;
tmp = strtol(optarg, &end, 10);
if (tmp >= 0 && tmp <= 10 && !*end && !errno) {
debug_level = static_cast<int>(tmp);
} else {
activate_flog_categories_by_pattern(str2wcstring(optarg));
}
activate_flog_categories_by_pattern(str2wcstring(optarg));
for (auto cat : get_flog_categories()) {
if (cat->enabled) {
std::fwprintf(stdout, L"Debug enabled for category: %ls\n", cat->name);

View File

@ -922,17 +922,7 @@ int main(int argc, char *argv[]) {
break;
}
case 'd': {
char *end;
long tmp;
errno = 0;
tmp = strtol(optarg, &end, 10);
if (tmp >= 0 && tmp <= 10 && !*end && !errno) {
debug_level = static_cast<int>(tmp);
} else {
activate_flog_categories_by_pattern(str2wcstring(optarg));
}
activate_flog_categories_by_pattern(str2wcstring(optarg));
for (auto cat : get_flog_categories()) {
if (cat->enabled) {
std::fwprintf(stdout, L"Debug enabled for category: %ls\n", cat->name);

View File

@ -154,9 +154,8 @@ static void apply_one_wildcard(const wcstring &wc_esc, bool sense) {
}
}
void activate_flog_categories_by_pattern(const wcstring &inwc) {
void activate_flog_categories_by_pattern(wcstring wc) {
// 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(L"-", s)) {

View File

@ -58,6 +58,8 @@ class category_list_t {
category_t event{L"event", L"Firing events"};
category_t exec{L"exec", L"Errors reported by exec (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"};
@ -180,7 +182,7 @@ extern owning_lock<logger_t> 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);
void activate_flog_categories_by_pattern(wcstring wc);
/// Set the file that flog should output to.
/// flog does not close this file.

View File

@ -37,9 +37,6 @@
/// The number of nanoseconds to sleep between attempts to call fork().
#define FORK_SLEEP_TIME 1000000
/// Fork error message.
#define FORK_ERROR "Could not create child process - exiting"
extern bool is_thompson_shell_script(const char *path);
static char *get_interpreter(const char *command, char *buffer, size_t buff_size);
@ -60,12 +57,12 @@ void report_setpgid_error(int err, bool is_parent, pid_t desired_pgid, const job
narrow_string_safe(argv0, p->argv0());
narrow_string_safe(command, j->command_wcstr());
debug_safe(1, "Could not send %s %s, '%s' in job %s, '%s' from group %s to group %s",
FLOGF_SAFE(warning, "Could not send %s %s, '%s' in job %s, '%s' from group %s to group %s",
is_parent ? "child" : "self", pid_buff, argv0, job_id_buff, command, getpgid_buff,
job_pgid_buff);
if (is_windows_subsystem_for_linux() && errno == EPERM) {
debug_safe(1,
FLOGF_SAFE(warning,
"Please update to Windows 10 1809/17763 or higher to address known issues "
"with process groups and zombie processes.");
}
@ -95,7 +92,7 @@ int execute_setpgid(pid_t pid, pid_t pgroup, bool is_parent) {
// the case in fish, anywhere) or to change the process group ID of a session
// leader (again, can never be the case). I'm pretty sure this is a WSL bug, as
// we see the same with tcsetpgrp(2) in other places and it disappears on retry.
debug_safe(2, "setpgid(2) returned EPERM. Retrying");
FLOGF_SAFE(proc_pgroup, "setpgid(2) returned EPERM. Retrying");
continue;
}
#ifdef __BSD__
@ -134,7 +131,7 @@ int child_setup_process(pid_t new_termowner, pid_t fish_pgrp, const job_t &job,
}
if (err < 0) {
if (is_forked) {
debug_safe(4, "redirect_in_child_after_fork failed in child_setup_process");
FLOGF_SAFE(warning, "failed to set up file descriptors in child_setup_process");
exit_without_destructors(1);
}
return err;
@ -177,7 +174,7 @@ pid_t execute_fork() {
// Make sure we have no outstanding threads before we fork. This is a pretty sketchy thing
// to do here, both because exec.cpp shouldn't have to know about iothreads, and because the
// completion handlers may do unexpected things.
debug_safe(4, "waiting for threads to drain.");
FLOGF_SAFE(iothread, "waiting for threads to drain.");
iothread_drain_all();
}
@ -205,7 +202,6 @@ pid_t execute_fork() {
}
}
debug_safe(0, FORK_ERROR);
safe_perror("fork");
FATAL_EXIT();
return 0;
@ -331,8 +327,6 @@ maybe_t<pid_t> posix_spawner_t::spawn(const char *cmd, char *const argv[], char
void safe_report_exec_error(int err, const char *actual_cmd, const char *const *argv,
const char *const *envv) {
debug_safe(0, "Failed to execute process '%s'. Reason:", actual_cmd);
switch (err) {
case E2BIG: {
char sz1[128], sz2[128];
@ -355,38 +349,35 @@ void safe_report_exec_error(int err, const char *actual_cmd, const char *const *
if (arg_max > 0) {
if (sz >= static_cast<unsigned long long>(arg_max)) {
format_size_safe(sz2, static_cast<unsigned long long>(arg_max));
debug_safe(
0,
"The total size of the argument and environment lists %s exceeds the "
"operating system limit of %s.",
sz1, sz2);
FLOGF_SAFE(exec,
"Failed to execute process '%s': the size of argument and "
"environment lists %s exceeds the OS limit of %s.",
actual_cmd, sz1, sz2);
} else {
// MAX_ARG_STRLEN, a linux thing that limits the size of one argument. It's
// defined in binfmts.h, but we don't want to include that just to be able to
// print the real limit.
debug_safe(0,
"One of your arguments exceeds the operating system's argument "
"length limit.");
FLOGF_SAFE(exec,
"Failed to execute process '%s': An argument exceeds the OS "
"argument length limit.");
}
} else {
debug_safe(0,
"The total size of the argument and environment lists (%s) exceeds the "
FLOGF_SAFE(exec,
"Failed to execute process '%s': The total size of the argument and "
"environment lists (%s) exceeds the "
"operating system limit.",
sz1);
actual_cmd, sz1);
}
debug_safe(0, "Try running the command again with fewer arguments.");
break;
}
case ENOEXEC: {
const char *err = safe_strerror(errno);
debug_safe(0, "exec: %s", err);
debug_safe(0,
"The file '%s' is marked as an executable but could not be run by the "
"operating system.",
actual_cmd);
const char *err_text = safe_strerror(err);
FLOGF_SAFE(
exec,
"%s. The file '%s' is marked as an executable but could not be run by the "
"operating system.",
err_text, actual_cmd);
break;
}
@ -402,29 +393,34 @@ void safe_report_exec_error(int err, const char *actual_cmd, const char *const *
// Detect windows line endings and complain specifically about them.
auto len = strlen(interpreter);
if (len && interpreter[len - 1] == '\r') {
debug_safe(0,
"The file uses windows line endings (\\r\\n). Run dos2unix or "
"similar to fix it.");
FLOGF_SAFE(exec,
"Failed to execute process '%s': The file uses windows line "
"endings (\\r\\n). Run dos2unix or similar to fix it.",
actual_cmd);
} else {
debug_safe(0,
"The file '%s' specified the interpreter '%s', which is not an "
FLOGF_SAFE(exec,
"Failed to execute process '%s': The file specified the interpreter "
"'%s', which is not an "
"executable command.",
actual_cmd, interpreter);
}
} else {
debug_safe(0, "The file '%s' does not exist or could not be executed.", actual_cmd);
FLOGF_SAFE(exec,
"Failed to execute process '%s': The file does not exist or could not "
"be executed.",
actual_cmd);
}
break;
}
case ENOMEM: {
debug_safe(0, "Out of memory");
FLOGF_SAFE(exec, "Out of memory");
break;
}
default: {
const char *err = safe_strerror(errno);
debug_safe(0, "exec: %s", err);
FLOGF_SAFE(exec, "%s", err);
break;
}
}

View File

@ -47,14 +47,10 @@ set -g fish_use_posix_spawn 1
echo $status
rm file.fish
#CHECK: 126
#CHECKERR: Failed {{.*}}
#CHECKERR: exec: {{.*}}
#CHECKERR: {{.*}}
#CHECKERR: exec: {{.*}}{{.*}}
#CHECK: 126
#CHECKERR: Failed {{.*}}
#CHECKERR: exec: {{.*}}
#CHECKERR: {{.*}}
# On to NUL bytes.
@ -70,25 +66,17 @@ echo -n -e 'true\x00' >file
sleep 0.1
runfile
#CHECK: 126
#CHECKERR: Failed {{.*}}
#CHECKERR: exec: {{.*}}
#CHECKERR: {{.*}}
#CHECK: 126
#CHECKERR: Failed {{.*}}
#CHECKERR: exec: {{.*}}
#CHECKERR: {{.*}}
# Doesn't meet our heuristic as there is no lowercase before newline.
echo -n -e 'NOPE\n\x00' >file
sleep 0.1
runfile
#CHECK: 126
#CHECKERR: Failed {{.*}}
#CHECKERR: exec: {{.*}}
#CHECKERR: {{.*}}
#CHECK: 126
#CHECKERR: Failed {{.*}}
#CHECKERR: exec: {{.*}}
#CHECKERR: {{.*}}