[libc] Display unit test runtime for hosted environments

[gchatelet]

Summary

With more tests added to LLVM libc each week we want to keep track of unittest's runtime, especially for low end build bots.

Top offender can be tracked with a bit of scripting (spoiler alert, mem function sweep tests are in the top ones)

ninja check-libc | grep "ms)" | awk '{print $(NF-1),$0}' | sort -nr | cut -f2- -d' '

Unfortunately this doesn't work for hermetic tests since clock is unavailable.

[sivachandra]

libc/test/UnitTest/LibcTest.cpp

167

clock() return value wraps around after every N minutes. Should we check if clock() return value here is greater than start_time? If not, report "Unknown - try rerunning"?

[gchatelet]

• Address comments

[gchatelet]

• format

[gchatelet]

• rebase / reformat

[gchatelet]

• remove extra empty line

libc/test/UnitTest/LibcTest.cpp

 //===-- Implementation of the base class for libc unittests----------------===//
 //
 // Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
 // See https://llvm.org/LICENSE.txt for license information.
 // SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
 //
 //===----------------------------------------------------------------------===//
 
 #include "LibcTest.h"
 
 #include "src/__support/CPP/string.h"
 #include "src/__support/CPP/string_view.h"
 #include "src/__support/UInt128.h"
 #include "test/UnitTest/TestLogger.h"
 
+#if __STDC_HOSTED__
+#include <time.h>
+#else
+static long clock() { return 0; }
+#define CLOCKS_PER_SEC 1
+#endif
+
 namespace __llvm_libc {
 namespace testing {
 
 namespace internal {
 
 // When the value is UInt128, __uint128_t or wider, show its hexadecimal digits.
 template <typename T>
 cpp::enable_if_t<cpp::is_integral_v<T> && cpp::is_unsigned_v<T> &&
for (Test *T = Start; T != nullptr; T = T->Next) {
     cpp::string StrTestName(TestName);
     constexpr auto GREEN = "\033[32m";
     constexpr auto RED = "\033[31m";
     constexpr auto RESET = "\033[0m";
     if ((TestFilter != nullptr) && (StrTestName != TestFilter)) {
       continue;
     }
     tlog << GREEN << "[ RUN      ] " << RESET << TestName << '\n';
+    [[maybe_unused]] const auto start_time = clock();
     RunContext Ctx;
     T->SetUp();
     T->setContext(&Ctx);
     T->Run();
     T->TearDown();
+    [[maybe_unused]] const auto end_time = clock();
     auto Result = Ctx.status();
     switch (Result) {
     case RunContext::Result_Fail:
       tlog << RED << "[  FAILED  ] " << RESET << TestName << '\n';
       ++FailCount;
       break;
     case RunContext::Result_Pass:
-      tlog << GREEN << "[       OK ] " << RESET << TestName << '\n';
+      tlog << GREEN << "[       OK ] " << RESET << TestName;
+#if __STDC_HOSTED__
+      tlog << " (took ";
+      if (start_time > end_time) {
+        tlog << "unknown - try rerunning)\n";
+      } else {
+        const auto duration = end_time - start_time;
+        const uint64_t duration_ms = duration * 1000 / CLOCKS_PER_SEC;
+        tlog << duration_ms << " ms)\n";
+      }
+#else
+      tlog << '\n';
+#endif
       break;
     }
     ++TestCount;
   }
 
   if (TestCount > 0) {
     tlog << "Ran " << TestCount << " tests. "
          << " PASS: " << TestCount - FailCount << ' ' << " FAIL: " << FailCount