From 3df93d4af3b67800cdbdfe9ff71b6bb366401d92 Mon Sep 17 00:00:00 2001 From: Sultan Alsawaf Date: Mon, 4 Oct 2021 12:09:32 -0700 Subject: [PATCH] staprun: fix warning/error/dbug eprintf() races causing garbled output There are lots of races when printing warnings/errors/dbugs in staprun because multiple eprintf() calls are used to print a single message and stderr is not line-buffered. As a result, warnings/errors/dbugs race with the relayfs reader threads printing to stdout and with other stap scripts running concurrently in the same PTY. This causes the messages printed to stderr and stdout to be garbled. Fix all of this by using a single eprintf() for each warning/error/dbug message, and by making stderr line-buffered so that we don't need to worry about differing libc implementations potentially flushing a single message in chunks rather than flushing the whole message in one go. --- staprun/common.c | 21 +-------------- staprun/stapio.c | 10 +++++++ staprun/staprun.c | 10 +++++++ staprun/staprun.h | 68 ++++++++++++++++++++++++++++++++--------------- 4 files changed, 68 insertions(+), 41 deletions(-) diff --git a/staprun/common.c b/staprun/common.c index e8b542662..0a6fafa9f 100644 --- a/staprun/common.c +++ b/staprun/common.c @@ -511,8 +511,7 @@ static void fatal_handler (int signum) int rc; char *str = strsignal(signum); rc = write (STDERR_FILENO, ERR_MSG, sizeof(ERR_MSG)); - rc = write (STDERR_FILENO, str, strlen(str)); - rc = write (STDERR_FILENO, "\n", 1); + fprintf(stderr, "%s\n", str); (void) rc; /* notused */ _exit(1); } @@ -698,24 +697,6 @@ void switch_syslog(const char *name) color_errors = 0; } -void print_color(const char *type) -{ - if (!color_errors) - return; - - if (type == NULL) // Reset - eprintf("\033[m\033[K"); - else { - char *seq = parse_stap_color(type); - if (seq != NULL) { - eprintf("\033["); - eprintf("%s", seq); - eprintf("m\033[K"); - free(seq); - } - } -} - /* Parse SYSTEMTAP_COLORS and returns the SGR parameter(s) for the given type. The env var SYSTEMTAP_COLORS must be in the following format: 'key1=val1:key2=val2:' etc... where valid keys are 'error', 'warning', diff --git a/staprun/stapio.c b/staprun/stapio.c index 664896dae..d9e04e01b 100644 --- a/staprun/stapio.c +++ b/staprun/stapio.c @@ -25,6 +25,16 @@ char *__name__ = "stapio"; int main(int argc, char **argv) { + /* Force libc to make our stderr messages atomic by enabling line + buffering since stderr is unbuffered by default. Without this, libc + is at liberty to split a single stderr message into multiple writes + to the fd while holding flockfile(stderr). POSIX only guarantees that + a single write(2) is atomic; chaining several write(2) calls together + won't be atomic, and we don't want libc to do that within a single + *fprintf(stderr) call since it'll mangle messages printed across + different processes (*not* threads). */ + setlinebuf(stderr); + #if ENABLE_NLS setlocale (LC_ALL, ""); bindtextdomain (PACKAGE, LOCALEDIR); diff --git a/staprun/staprun.c b/staprun/staprun.c index 3bb358620..edd1bc67a 100644 --- a/staprun/staprun.c +++ b/staprun/staprun.c @@ -446,6 +446,16 @@ int main(int argc, char **argv) { int rc; + /* Force libc to make our stderr messages atomic by enabling line + buffering since stderr is unbuffered by default. Without this, libc + is at liberty to split a single stderr message into multiple writes + to the fd while holding flockfile(stderr). POSIX only guarantees that + a single write(2) is atomic; chaining several write(2) calls together + won't be atomic, and we don't want libc to do that within a single + *fprintf(stderr) call since it'll mangle messages printed across + different processes (*not* threads). */ + setlinebuf(stderr); + /* NB: Don't do the geteuid()!=0 check here, since we want to test command-line error-handling while running non-root. */ /* Get rid of a few standard environment variables (which */ diff --git a/staprun/staprun.h b/staprun/staprun.h index d4f368cf8..5c814b902 100644 --- a/staprun/staprun.h +++ b/staprun/staprun.h @@ -72,31 +72,55 @@ extern void eprintf(const char *fmt, ...); extern void switch_syslog(const char *name); -extern void print_color(const char *type); extern char *parse_stap_color(const char *type); -#define dbug(level, args...) do {if (verbose>=level) {eprintf("%s:%s:%d ",__name__,__FUNCTION__, __LINE__); eprintf(args);}} while (0) - extern char *__name__; /* print to stderr */ -#define err(args...) do { \ - print_color("error"); \ - eprintf(_("ERROR:")); \ - print_color(NULL); \ - eprintf(" "); \ - eprintf(args); \ - } while (0) - -#define warn(args...) do { \ - if (suppress_warnings) \ - break; \ - print_color("warning"); \ - eprintf(_("WARNING:")); \ - print_color(NULL); \ - eprintf(" "); \ - eprintf(args); \ - } while (0) +#define COLOR_FMT "\033[%sm\033[K" +#define COLOR_RESET "\033[m\033[K" +#define print_stderr(color, tag, fmt, ...) \ +do { \ + char *f, *seq; \ + int num; \ + \ + /* Build the final format string so there's only one eprintf() call */ \ + seq = color ? parse_stap_color(color) : NULL; \ + if (seq) \ + num = snprintf(NULL, 0, COLOR_FMT "%s " COLOR_RESET "%s", seq, \ + tag, fmt); \ + else \ + num = snprintf(NULL, 0, "%s %s", tag, fmt); \ + \ + f = malloc(num + 1); \ + if (!f) { \ + fprintf(stderr, "Memory allocation failed.\n"); \ + exit(-2); \ + } \ + \ + if (seq) { \ + sprintf(f, COLOR_FMT "%s " COLOR_RESET "%s", seq, tag, fmt); \ + free(seq); \ + } else { \ + sprintf(f, "%s %s", tag, fmt); \ + } \ + \ + eprintf(f, ##__VA_ARGS__); \ + free(f); \ +} while (0) + +#define err(fmt, ...) \ + print_stderr("error", _("ERROR:"), fmt, ##__VA_ARGS__) + +#define warn(fmt, ...) \ + print_stderr("warning", _("WARNING:"), fmt, ##__VA_ARGS__) + +#define dbug(level, fmt, ...) \ +do { \ + if (verbose >= level) \ + print_stderr(NULL, "%s:%s:%d", fmt, __name__, \ + __FUNCTION__, __LINE__, ##__VA_ARGS__); \ +} while (0) /* better perror() */ #define perr(args...) do { \ @@ -106,7 +130,9 @@ extern char *__name__; } while (0) /* Error messages. Use these for serious errors, not informational messages to stderr. */ -#define _err(args...) do {eprintf("%s:%s:%d: ERROR: ",__name__, __FUNCTION__, __LINE__); eprintf(args);} while(0) +#define _err(fmt, ...) \ + print_stderr(NULL, "%s:%s:%d: ERROR:", fmt, __name__, \ + __FUNCTION__, __LINE__, ##__VA_ARGS__) #define _perr(args...) do { \ int _errno = errno; \ _err(args); \ -- 2.43.5