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.

diff --git a/staprun/common.c b/staprun/common.c
index e8b54266215e22dfcf2d5224593478d1bad42c66..0a6fafa9f497cdce383b374c80ab1a6190381eb3 100644 (file)
--- 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 664896dae3ab99a4f5ad92247d358e2a2216ae67..d9e04e01bef51a1ec3ca71d82a27180afe45001c 100644 (file)
--- 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 3bb3586200d469b27f865d22be740a70f00799f8..edd1bc67a29e851c2bbf9b5d68107ff9f27308bd 100644 (file)
--- 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 d4f368cf85ecd569d1a74b03ae6c5705c3197ec1..5c814b9021d4e6dfc2cab32ab5ec1f98e879748e 100644 (file)
--- 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);                                     \