failtest: --tracepath

Useful for showing exactly where we inserted failures, and how long each
one took.

diff --git a/ccan/failtest/failtest.c b/ccan/failtest/failtest.c
index 4b5ab10ada23714123f65cfaf24f2e6a3909a72f..598a9e7930e933873ffbd9d02a3578d12d752472 100644 (file)
--- a/ccan/failtest/failtest.c
+++ b/ccan/failtest/failtest.c
@@ -10,6 +10,7 @@
 #include <sys/types.h>
 #include <sys/wait.h>
 #include <sys/stat.h>
+#include <sys/time.h>
 #include <assert.h>
 #include <ccan/read_write_all/read_write_all.h>
 #include <ccan/failtest/failtest_proto.h>
@@ -19,6 +20,8 @@
 bool (*failtest_hook)(struct failtest_call *history, unsigned num)
 = failtest_default_hook;
 
+static int tracefd = -1;
+
 unsigned int failtest_timeout_ms = 20000;
 
 const char *failpath;
@@ -63,6 +66,7 @@ bool (*failtest_exit_check)(struct failtest_call *history, unsigned num);
 static struct failtest_call *history = NULL;
 static unsigned int history_num = 0;
 static int control_fd = -1;
+static struct timeval start;
 
 static struct write_info *writes = NULL;
 static unsigned int writes_num = 0;
@@ -143,18 +147,18 @@ static bool read_write_info(int fd)
        return true;
 }
 
-static void print_reproduce(void)
+static char *failpath_string(void)
 {
        unsigned int i;
+       char *ret = malloc(history_num + 1);
 
-       printf("To reproduce: --failpath=");
        for (i = 0; i < history_num; i++) {
+               ret[i] = info_to_arg[history[i].type];
                if (history[i].fail)
-                       printf("%c", toupper(info_to_arg[history[i].type]));
-               else
-                       printf("%c", info_to_arg[history[i].type]);
+                       ret[i] = toupper(ret[i]);
        }
-       printf("\n");
+       ret[i] = '\0';
+       return ret;
 }
 
 static void tell_parent(enum info_type type)
@@ -166,13 +170,15 @@ static void tell_parent(enum info_type type)
 static void child_fail(const char *out, size_t outlen, const char *fmt, ...)
 {
        va_list ap;
+       char *path = failpath_string();
 
        va_start(ap, fmt);
        vfprintf(stderr, fmt, ap);
        va_end(ap);
 
        fprintf(stderr, "%.*s", (int)outlen, out);
-       print_reproduce();
+       printf("To reproduce: --failpath=%s\n", path);
+       free(path);
        tell_parent(FAILURE);
        exit(1);
 }
@@ -250,6 +256,18 @@ static void get_locks(void)
        lock_owner = getpid();
 }
 
+static void trace_str(const char *str)
+{
+       ssize_t ret;
+
+       while ((ret = write(tracefd, str, strlen(str))) <= 0) {
+               str += ret;
+               if (!*str)
+                       return;
+       }
+       err(1, "Writing trace.");
+}
+
 static bool should_fail(struct failtest_call *call)
 {
        int status;
@@ -286,6 +304,31 @@ static bool should_fail(struct failtest_call *call)
                err(1, "forking failed");
 
        if (child == 0) {
+               if (tracefd != -1) {
+                       struct timeval now;
+                       char str[50], *p;
+                       gettimeofday(&now, NULL);
+                       if (now.tv_usec < start.tv_usec) {
+                               now.tv_sec--;
+                               now.tv_usec += 1000000;
+                       }
+                       now.tv_usec -= start.tv_usec;
+                       now.tv_sec -= start.tv_sec;
+                       sprintf(str, "%u (%u.%02u): ", getpid(),
+                               (int)now.tv_sec, (int)now.tv_usec / 10000);
+                       trace_str(str);
+                       p = failpath_string();
+                       trace_str(p);
+                       free(p);
+                       trace_str("(");
+                       p = strchr(history[history_num-1].file, '/');
+                       if (p)
+                               trace_str(p+1);
+                       else
+                               trace_str(history[history_num-1].file);
+                       sprintf(str, ":%u)\n", history[history_num-1].line);
+                       trace_str(str);
+               }
                close(control[0]);
                close(output[0]);
                dup2(output[1], STDOUT_FILENO);
@@ -755,10 +798,17 @@ int failtest_fcntl(int fd, const char *file, unsigned line, int cmd, ...)
 
 void failtest_init(int argc, char *argv[])
 {
-       if (argc == 2
-           && strncmp(argv[1], "--failpath=", strlen("--failpath=")) == 0) {
-               failpath = argv[1] + strlen("--failpath=");
+       unsigned int i;
+
+       for (i = 1; i < argc; i++) {
+               if (!strncmp(argv[i], "--failpath=", strlen("--failpath="))) {
+                       failpath = argv[i] + strlen("--failpath=");
+               } else if (strcmp(argv[i], "--tracepath") == 0) {
+                       tracefd = dup(STDERR_FILENO);
+                       failtest_timeout_ms = -1;
+               }
        }
+       gettimeofday(&start, NULL);
 }
 
 /* Free up memory, so valgrind doesn't report leaks. */

diff --git a/ccan/failtest/test/run-history.c b/ccan/failtest/test/run-history.c
index 3b5220a518a803cbd0d8eb538e0932c1d153d653..dc5a3f96a4732f16c6232595f2578ea922a6799d 100644 (file)
--- a/ccan/failtest/test/run-history.c
+++ b/ccan/failtest/test/run-history.c
@@ -2,52 +2,9 @@
 #include <stdio.h>
 #include <stdarg.h>
 #include <ccan/tap/tap.h>
-
-#define printf saved_printf
-static int saved_printf(const char *fmt, ...);
-
-#define fprintf saved_fprintf
-static int saved_fprintf(FILE *ignored, const char *fmt, ...);
-
 /* Include the C files directly. */
 #include <ccan/failtest/failtest.c>
 
-static char *output = NULL;
-
-static int saved_vprintf(const char *fmt, va_list ap)
-{
-       int ret = vsnprintf(NULL, 0, fmt, ap);
-       int len = 0;
-
-       if (output)
-               len = strlen(output);
-
-       output = realloc(output, len + ret + 1);
-       return vsprintf(output + len, fmt, ap);
-}
-
-static int saved_printf(const char *fmt, ...)
-{
-       va_list ap;
-       int ret;
-
-       va_start(ap, fmt);
-       ret = saved_vprintf(fmt, ap);
-       va_end(ap);
-       return ret;
-}      
-
-static int saved_fprintf(FILE *ignored, const char *fmt, ...)
-{
-       va_list ap;
-       int ret;
-
-       va_start(ap, fmt);
-       ret = saved_vprintf(fmt, ap);
-       va_end(ap);
-       return ret;
-}      
-
 int main(void)
 {
        struct failtest_call *call;
@@ -60,6 +17,7 @@ int main(void)
        struct write_call write_call;
        char buf[20];
        unsigned int i;
+       char *path;
 
        /* This is how many tests you plan to run */
        plan_tests(47);
@@ -149,18 +107,16 @@ int main(void)
        for (i = 0; i < history_num; i++)
                history[i].fail = false;
 
-       print_reproduce();
-       ok1(strcmp(output, "To reproduce: --failpath=cmeoprw\n") == 0);
-       free(output);
-       output = NULL;
+       path = failpath_string();
+       ok1(strcmp(path, "cmeoprw") == 0);
+       free(path);
 
        for (i = 0; i < history_num; i++)
                history[i].fail = true;
 
-       print_reproduce();
-       ok1(strcmp(output, "To reproduce: --failpath=CMEOPRW\n") == 0);
-       free(output);
-       output = NULL;
+       path = failpath_string();
+       ok1(strcmp(path, "CMEOPRW") == 0);
+       free(path);
 
        return exit_status();
 }