Adds --gtest_print_test for printing the elapsed time of tests.

4 files changed, 241 insertions, 5 deletions

diff --git a/test/gtest_output_test.py b/test/gtest_output_test.py
index ee766ffd..05f49dc4 100755
--- a/test/gtest_output_test.py
+++ b/test/gtest_output_test.py
@@ -58,8 +58,10 @@ else:
   PROGRAM = 'gtest_output_test_'
   GOLDEN_NAME = 'gtest_output_test_golden_lin.txt'
 
-COMMAND = os.path.join(gtest_test_utils.GetBuildDir(),
-                       PROGRAM) + ' --gtest_color=yes'
+PROGRAM_PATH = os.path.join(gtest_test_utils.GetBuildDir(), PROGRAM)
+COMMAND_WITH_COLOR = PROGRAM_PATH + ' --gtest_color=yes'
+COMMAND_WITH_TIME = (PROGRAM_PATH + ' --gtest_print_time '
+                     + '--gtest_filter="FatalFailureTest.*:LoggingTest.*"')
 
 GOLDEN_PATH = os.path.join(gtest_test_utils.GetSourceDir(),
                            GOLDEN_NAME)
@@ -94,12 +96,19 @@ def RemoveStackTraces(output):
                 'Stack trace: (omitted)\n\n', output)
 
 
+def RemoveTime(output):
+  """Removes all time information from a Google Test program's output."""
+
+  return re.sub(r'\(\d+ ms', '(? ms', output)
+
+
 def NormalizeOutput(output):
   """Normalizes output (the output of gtest_output_test_.exe)."""
 
   output = ToUnixLineEnding(output)
   output = RemoveLocations(output)
   output = RemoveStackTraces(output)
+  output = RemoveTime(output)
   return output
 
 
@@ -165,8 +174,8 @@ def GetCommandOutput(cmd):
 
 class GTestOutputTest(unittest.TestCase):
   def testOutput(self):
-    output = GetCommandOutput(COMMAND)
-
+    output = (GetCommandOutput(COMMAND_WITH_COLOR) +
+              GetCommandOutput(COMMAND_WITH_TIME))
     golden_file = open(GOLDEN_PATH, 'rb')
     golden = golden_file.read()
     golden_file.close()
@@ -176,7 +185,8 @@ class GTestOutputTest(unittest.TestCase):
 
 if __name__ == '__main__':
   if sys.argv[1:] == [GENGOLDEN_FLAG]:
-    output = GetCommandOutput(COMMAND)
+    output = (GetCommandOutput(COMMAND_WITH_COLOR) +
+              GetCommandOutput(COMMAND_WITH_TIME))
     golden_file = open(GOLDEN_PATH, 'wb')
     golden_file.write(output)
     golden_file.close()
diff --git a/test/gtest_output_test_golden_lin.txt b/test/gtest_output_test_golden_lin.txt
index bfcc9a9b..1da3bf30 100644
--- a/test/gtest_output_test_golden_lin.txt
+++ b/test/gtest_output_test_golden_lin.txt
@@ -381,3 +381,73 @@ Expected fatal failure.
 [  FAILED  ] ExpectFatalFailureTest.FailsWhenStatementReturns
 
 26 FAILED TESTS
+The non-test part of the code is expected to have 2 failures.
+
+gtest_output_test_.cc:#: Failure
+Value of: false
+  Actual: false
+Expected: true
+gtest_output_test_.cc:#: Failure
+Value of: 3
+Expected: 2
+Note: Google Test filter = FatalFailureTest.*:LoggingTest.*
+[==========] Running 4 tests from 2 test cases.
+[----------] Global test environment set-up.
+FooEnvironment::SetUp() called.
+BarEnvironment::SetUp() called.
+[----------] 3 tests from FatalFailureTest
+[ RUN      ] FatalFailureTest.FatalFailureInSubroutine
+(expecting a failure that x should be 1)
+gtest_output_test_.cc:#: Failure
+Value of: x
+  Actual: 2
+Expected: 1
+[  FAILED  ] FatalFailureTest.FatalFailureInSubroutine (? ms)
+[ RUN      ] FatalFailureTest.FatalFailureInNestedSubroutine
+(expecting a failure that x should be 1)
+gtest_output_test_.cc:#: Failure
+Value of: x
+  Actual: 2
+Expected: 1
+[  FAILED  ] FatalFailureTest.FatalFailureInNestedSubroutine (? ms)
+[ RUN      ] FatalFailureTest.NonfatalFailureInSubroutine
+(expecting a failure on false)
+gtest_output_test_.cc:#: Failure
+Value of: false
+  Actual: false
+Expected: true
+[  FAILED  ] FatalFailureTest.NonfatalFailureInSubroutine (? ms)
+[----------] 3 tests from FatalFailureTest (? ms total)
+
+[----------] 1 test from LoggingTest
+[ RUN      ] LoggingTest.InterleavingLoggingAndAssertions
+(expecting 2 failures on (3) >= (a[i]))
+i == 0
+i == 1
+gtest_output_test_.cc:#: Failure
+Expected: (3) >= (a[i]), actual: 3 vs 9
+i == 2
+i == 3
+gtest_output_test_.cc:#: Failure
+Expected: (3) >= (a[i]), actual: 3 vs 6
+[  FAILED  ] LoggingTest.InterleavingLoggingAndAssertions (? ms)
+[----------] 1 test from LoggingTest (? ms total)
+
+[----------] Global test environment tear-down
+BarEnvironment::TearDown() called.
+gtest_output_test_.cc:#: Failure
+Failed
+Expected non-fatal failure.
+FooEnvironment::TearDown() called.
+gtest_output_test_.cc:#: Failure
+Failed
+Expected fatal failure.
+[==========] 4 tests from 2 test cases ran. (? ms total)
+[  PASSED  ] 0 tests.
+[  FAILED  ] 4 tests, listed below:
+[  FAILED  ] FatalFailureTest.FatalFailureInSubroutine
+[  FAILED  ] FatalFailureTest.FatalFailureInNestedSubroutine
+[  FAILED  ] FatalFailureTest.NonfatalFailureInSubroutine
+[  FAILED  ] LoggingTest.InterleavingLoggingAndAssertions
+
+ 4 FAILED TESTS
diff --git a/test/gtest_output_test_golden_win.txt b/test/gtest_output_test_golden_win.txt
index eb476ecd..9a13da95 100644
--- a/test/gtest_output_test_golden_win.txt
+++ b/test/gtest_output_test_golden_win.txt
@@ -358,3 +358,64 @@ Expected fatal failure.
 [  FAILED  ] ExpectFatalFailureTest.FailsWhenStatementReturns
 
 29 FAILED TESTS
+The non-test part of the code is expected to have 2 failures.
+
+gtest_output_test_.cc:#: error: Value of: false
+  Actual: false
+Expected: true
+gtest_output_test_.cc:#: error: Value of: 3
+Expected: 2
+Note: Google Test filter = FatalFailureTest.*:LoggingTest.*
+[==========] Running 4 tests from 2 test cases.
+[----------] Global test environment set-up.
+FooEnvironment::SetUp() called.
+BarEnvironment::SetUp() called.
+[----------] 3 tests from FatalFailureTest
+[ RUN      ] FatalFailureTest.FatalFailureInSubroutine
+(expecting a failure that x should be 1)
+gtest_output_test_.cc:#: error: Value of: x
+  Actual: 2
+Expected: 1
+[  FAILED  ] FatalFailureTest.FatalFailureInSubroutine (? ms)
+[ RUN      ] FatalFailureTest.FatalFailureInNestedSubroutine
+(expecting a failure that x should be 1)
+gtest_output_test_.cc:#: error: Value of: x
+  Actual: 2
+Expected: 1
+[  FAILED  ] FatalFailureTest.FatalFailureInNestedSubroutine (? ms)
+[ RUN      ] FatalFailureTest.NonfatalFailureInSubroutine
+(expecting a failure on false)
+gtest_output_test_.cc:#: error: Value of: false
+  Actual: false
+Expected: true
+[  FAILED  ] FatalFailureTest.NonfatalFailureInSubroutine (? ms)
+[----------] 3 tests from FatalFailureTest (? ms total)
+
+[----------] 1 test from LoggingTest
+[ RUN      ] LoggingTest.InterleavingLoggingAndAssertions
+(expecting 2 failures on (3) >= (a[i]))
+i == 0
+i == 1
+gtest_output_test_.cc:#: error: Expected: (3) >= (a[i]), actual: 3 vs 9
+i == 2
+i == 3
+gtest_output_test_.cc:#: error: Expected: (3) >= (a[i]), actual: 3 vs 6
+[  FAILED  ] LoggingTest.InterleavingLoggingAndAssertions (? ms)
+[----------] 1 test from LoggingTest (? ms total)
+
+[----------] Global test environment tear-down
+BarEnvironment::TearDown() called.
+gtest_output_test_.cc:#: error: Failed
+Expected non-fatal failure.
+FooEnvironment::TearDown() called.
+gtest_output_test_.cc:#: error: Failed
+Expected fatal failure.
+[==========] 4 tests from 2 test cases ran. (? ms total)
+[  PASSED  ] 0 tests.
+[  FAILED  ] 4 tests, listed below:
+[  FAILED  ] FatalFailureTest.FatalFailureInSubroutine
+[  FAILED  ] FatalFailureTest.FatalFailureInNestedSubroutine
+[  FAILED  ] FatalFailureTest.NonfatalFailureInSubroutine
+[  FAILED  ] LoggingTest.InterleavingLoggingAndAssertions
+
+ 4 FAILED TESTS
diff --git a/test/gtest_unittest.cc b/test/gtest_unittest.cc
index 02799a4f..e88a8d02 100644
--- a/test/gtest_unittest.cc
+++ b/test/gtest_unittest.cc
@@ -808,6 +808,7 @@ class GTestFlagSaverTest : public testing::Test {
     testing::GTEST_FLAG(filter) = "";
     testing::GTEST_FLAG(list_tests) = false;
     testing::GTEST_FLAG(output) = "";
+    testing::GTEST_FLAG(print_time) = false;
     testing::GTEST_FLAG(repeat) = 1;
   }
 
@@ -827,6 +828,7 @@ class GTestFlagSaverTest : public testing::Test {
     EXPECT_STREQ("", testing::GTEST_FLAG(filter).c_str());
     EXPECT_FALSE(testing::GTEST_FLAG(list_tests));
     EXPECT_STREQ("", testing::GTEST_FLAG(output).c_str());
+    EXPECT_FALSE(testing::GTEST_FLAG(print_time));
     EXPECT_EQ(1, testing::GTEST_FLAG(repeat));
 
     testing::GTEST_FLAG(break_on_failure) = true;
@@ -835,6 +837,7 @@ class GTestFlagSaverTest : public testing::Test {
     testing::GTEST_FLAG(filter) = "abc";
     testing::GTEST_FLAG(list_tests) = true;
     testing::GTEST_FLAG(output) = "xml:foo.xml";
+    testing::GTEST_FLAG(print_time) = true;
     testing::GTEST_FLAG(repeat) = 100;
   }
  private:
@@ -3471,6 +3474,7 @@ struct Flags {
             filter(""),
             list_tests(false),
             output(""),
+            print_time(false),
             repeat(1) {}
 
   // Factory methods.
@@ -3515,6 +3519,14 @@ struct Flags {
     return flags;
   }
 
+  // Creates a Flags struct where the gtest_print_time flag has the given
+  // value.
+  static Flags PrintTime(bool print_time) {
+    Flags flags;
+    flags.print_time = print_time;
+    return flags;
+  }
+
   // Creates a Flags struct where the gtest_repeat flag has the given
   // value.
   static Flags Repeat(Int32 repeat) {
@@ -3529,6 +3541,7 @@ struct Flags {
   const char* filter;
   bool list_tests;
   const char* output;
+  bool print_time;
   Int32 repeat;
 };
 
@@ -3542,6 +3555,7 @@ class InitGoogleTestTest : public testing::Test {
     GTEST_FLAG(filter) = "";
     GTEST_FLAG(list_tests) = false;
     GTEST_FLAG(output) = "";
+    GTEST_FLAG(print_time) = false;
     GTEST_FLAG(repeat) = 1;
   }
 
@@ -3563,6 +3577,7 @@ class InitGoogleTestTest : public testing::Test {
     EXPECT_STREQ(expected.filter, GTEST_FLAG(filter).c_str());
     EXPECT_EQ(expected.list_tests, GTEST_FLAG(list_tests));
     EXPECT_STREQ(expected.output, GTEST_FLAG(output).c_str());
+    EXPECT_EQ(expected.print_time, GTEST_FLAG(print_time));
     EXPECT_EQ(expected.repeat, GTEST_FLAG(repeat));
   }
 
@@ -3950,6 +3965,86 @@ TEST_F(InitGoogleTestTest, OutputXmlDirectory) {
   TEST_PARSING_FLAGS(argv, argv2, Flags::Output("xml:directory/path/"));
 }
 
+// Tests having a --gtest_print_time flag
+TEST_F(InitGoogleTestTest, PrintTimeFlag) {
+    const char* argv[] = {
+      "foo.exe",
+      "--gtest_print_time",
+      NULL
+    };
+
+    const char* argv2[] = {
+      "foo.exe",
+      NULL
+    };
+
+    TEST_PARSING_FLAGS(argv, argv2, Flags::PrintTime(true));
+}
+
+// Tests having a --gtest_print_time flag with a "true" value
+TEST_F(InitGoogleTestTest, PrintTimeTrue) {
+    const char* argv[] = {
+      "foo.exe",
+      "--gtest_print_time=1",
+      NULL
+    };
+
+    const char* argv2[] = {
+      "foo.exe",
+      NULL
+    };
+
+    TEST_PARSING_FLAGS(argv, argv2, Flags::PrintTime(true));
+}
+
+// Tests having a --gtest_print_time flag with a "false" value
+TEST_F(InitGoogleTestTest, PrintTimeFalse) {
+    const char* argv[] = {
+      "foo.exe",
+      "--gtest_print_time=0",
+      NULL
+    };
+
+    const char* argv2[] = {
+      "foo.exe",
+      NULL
+    };
+
+    TEST_PARSING_FLAGS(argv, argv2, Flags::PrintTime(false));
+}
+
+// Tests parsing --gtest_print_time=f.
+TEST_F(InitGoogleTestTest, PrintTimeFalse_f) {
+  const char* argv[] = {
+    "foo.exe",
+    "--gtest_print_time=f",
+    NULL
+  };
+
+  const char* argv2[] = {
+    "foo.exe",
+    NULL
+  };
+
+  TEST_PARSING_FLAGS(argv, argv2, Flags::PrintTime(false));
+}
+
+// Tests parsing --gtest_print_time=F.
+TEST_F(InitGoogleTestTest, PrintTimeFalse_F) {
+  const char* argv[] = {
+    "foo.exe",
+    "--gtest_print_time=F",
+    NULL
+  };
+
+  const char* argv2[] = {
+    "foo.exe",
+    NULL
+  };
+
+  TEST_PARSING_FLAGS(argv, argv2, Flags::PrintTime(false));
+}
+
 // Tests parsing --gtest_repeat=number
 TEST_F(InitGoogleTestTest, Repeat) {
   const char* argv[] = {