LU-1205 tests: add timestamps to sanityn 18 mmap

The sanityn.sh test_18 mmap_sanity.c test sometimes takes over
an hour to run, and sometimes only seconds.  Add timestamps to
the subtest results so that it is possible to debug where that
time is being spent.

Signed-off-by: Andreas Dilger <adilger@whamcloud.com>
Change-Id: Ie33c46d9b72083c79112455ac9df6f357dc7cab0
Reviewed-on: http://review.whamcloud.com/2290
Tested-by: Hudson
Tested-by: Maloo <whamcloud.maloo@gmail.com>
Reviewed-by: Yu Jian <yujian@whamcloud.com>
Reviewed-by: Oleg Drokin <green@whamcloud.com>

diff --git a/lustre/tests/mmap_sanity.c b/lustre/tests/mmap_sanity.c
index 210fb13..786a12c 100644 (file)
--- a/lustre/tests/mmap_sanity.c
+++ b/lustre/tests/mmap_sanity.c
@@ -49,6 +49,7 @@
 #include <netdb.h>
 #include <string.h>
 #include <sys/wait.h>
+#include <sys/time.h>
 
 char *dir = NULL, *dir2 = NULL;
 long page_size;
@@ -827,13 +828,24 @@ int main(int argc, char **argv)
         }
 
         for (test = tests; test->tc; test++) {
-                char *rs = "skip";
-                rc = 0;
+                double duration;
+                char *rs;
+
                 if (test->node_cnt == 1 || dir2 != NULL) {
+                        struct timeval start, end;
+
+                        gettimeofday(&start, NULL);
                         rc = test->test_fn(dir);
-                        rs = rc ? "fail" : "pass";
+                        gettimeofday(&end, NULL);
+
+                        duration = (double)(end.tv_sec - start.tv_sec) +
+                                (double)(end.tv_usec - start.tv_usec) / 1000000;
+                        rs = rc ? "FAIL" : "PASS";
+                } else {
+                        duration = 0.0;
+                        rs = "SKIP";
                 }
-                fprintf(stderr, "%s (%s)\n", test->desc, rs);
+                fprintf(stderr, "%s (%s, %.5gs)\n", test->desc, rs, duration);
                 if (rc)
                         break;
         }