Time profiler: small fixes and optimizations

Summary: Fixes from Roman's review here: https://reviews.llvm.org/D58675#1465336

Reviewers: lebedev.ri

Subscribers: hiraditya, mgrang, cfe-commits, llvm-commits

Tags: #clang, #llvm

Differential Revision: https://reviews.llvm.org/D60663

llvm-svn: 358448

clang/tools/driver/cc1_main.cpp

@@ -239,7 +239,7 @@ int cc1_main(ArrayRef<const char *> Argv, const char *Argv0, void *MainAddr) {
                                 /*Extension=*/"json",
                                 /*useTemporary=*/false);
 
-    llvm::timeTraceProfilerWrite(profilerOutput);
+    llvm::timeTraceProfilerWrite(*profilerOutput);
     llvm::timeTraceProfilerCleanup();
   }
 

llvm/include/llvm/Support/TimeProfiler.h

@@ -1,9 +1,8 @@
 //===- llvm/Support/TimeProfiler.h - Hierarchical Time Profiler -*- C++ -*-===//
 //
-//                     The LLVM Compiler Infrastructure
-//
-// This file is distributed under the University of Illinois Open Source
-// License. See LICENSE.TXT for details.
+// 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
 //
 //===----------------------------------------------------------------------===//
 
@@ -33,7 +32,7 @@ inline bool timeTraceProfilerEnabled() {
 /// Write profiling data to output file.
 /// Data produced is JSON, in Chrome "Trace Event" format, see
 /// https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview
-void timeTraceProfilerWrite(std::unique_ptr<raw_pwrite_stream> &OS);
+void timeTraceProfilerWrite(raw_pwrite_stream &OS);
 
 /// Manually begin a time section, with the given \p Name and \p Detail.
 /// Profiler copies the string data, so the pointers can be given into
@@ -51,6 +50,13 @@ void timeTraceProfilerEnd();
 /// the section; and when it is destroyed, it stops it. If the time profiler
 /// is not initialized, the overhead is a single branch.
 struct TimeTraceScope {
+
+  TimeTraceScope() = delete;
+  TimeTraceScope(const TimeTraceScope &) = delete;
+  TimeTraceScope &operator=(const TimeTraceScope &) = delete;
+  TimeTraceScope(TimeTraceScope &&) = delete;
+  TimeTraceScope &operator=(TimeTraceScope &&) = delete;
+
   TimeTraceScope(StringRef Name, StringRef Detail) {
     if (TimeTraceProfilerInstance != nullptr)
       timeTraceProfilerBegin(Name, Detail);

llvm/lib/Support/TimeProfiler.cpp

@@ -1,30 +1,35 @@
 //===-- TimeProfiler.cpp - Hierarchical Time Profiler ---------------------===//
 //
-//                     The LLVM Compiler Infrastructure
-//
-// This file is distributed under the University of Illinois Open Source
-// License. See LICENSE.TXT for details.
+// 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
 //
 //===----------------------------------------------------------------------===//
 //
-/// \file Hierarchical time profiler implementation.
+// This file implements hierarchical time profiler.
 //
 //===----------------------------------------------------------------------===//
 
 #include "llvm/Support/TimeProfiler.h"
 #include "llvm/ADT/StringExtras.h"
 #include "llvm/ADT/StringMap.h"
+#include "llvm/Support/CommandLine.h"
 #include "llvm/Support/FileSystem.h"
 #include <cassert>
 #include <chrono>
 #include <string>
-#include <unordered_map>
 #include <vector>
 
 using namespace std::chrono;
 
 namespace llvm {
 
+static cl::opt<unsigned> TimeTraceGranularity(
+    "time-trace-granularity",
+    cl::desc(
+        "Minimum time granularity (in microseconds) traced by time profiler"),
+    cl::init(500));
+
 TimeTraceProfiler *TimeTraceProfilerInstance = nullptr;
 
 static std::string escapeString(StringRef Src) {
@@ -61,27 +66,30 @@ struct Entry {
   DurationType Duration;
   std::string Name;
   std::string Detail;
+
+  Entry(time_point<steady_clock> &&S, DurationType &&D, std::string &&N,
+        std::string &&Dt)
+      : Start(std::move(S)), Duration(std::move(D)), Name(std::move(N)),
+        Detail(std::move(Dt)){};
 };
 
 struct TimeTraceProfiler {
   TimeTraceProfiler() {
-    Stack.reserve(8);
-    Entries.reserve(128);
     StartTime = steady_clock::now();
   }
 
   void begin(std::string Name, llvm::function_ref<std::string()> Detail) {
-    Entry E = {steady_clock::now(), {}, Name, Detail()};
-    Stack.push_back(std::move(E));
+    Stack.emplace_back(steady_clock::now(), DurationType{}, std::move(Name),
+                       Detail());
   }
 
   void end() {
     assert(!Stack.empty() && "Must call begin() first");
     auto &E = Stack.back();
     E.Duration = steady_clock::now() - E.Start;
 
-    // Only include sections longer than 500us.
-    if (duration_cast<microseconds>(E.Duration).count() > 500)
+    // Only include sections longer than TimeTraceGranularity msec.
+    if (duration_cast<microseconds>(E.Duration).count() > TimeTraceGranularity)
       Entries.emplace_back(E);
 
     // Track total time taken by each "name", but only the topmost levels of
@@ -100,53 +108,53 @@ struct TimeTraceProfiler {
     Stack.pop_back();
   }
 
-  void Write(std::unique_ptr<raw_pwrite_stream> &OS) {
+  void Write(raw_pwrite_stream &OS) {
     assert(Stack.empty() &&
            "All profiler sections should be ended when calling Write");
 
-    *OS << "{ \"traceEvents\": [\n";
+    OS << "{ \"traceEvents\": [\n";
 
     // Emit all events for the main flame graph.
     for (const auto &E : Entries) {
       auto StartUs = duration_cast<microseconds>(E.Start - StartTime).count();
       auto DurUs = duration_cast<microseconds>(E.Duration).count();
-      *OS << "{ \"pid\":1, \"tid\":0, \"ph\":\"X\", \"ts\":" << StartUs
-          << ", \"dur\":" << DurUs << ", \"name\":\"" << escapeString(E.Name)
-          << "\", \"args\":{ \"detail\":\"" << escapeString(E.Detail)
-          << "\"} },\n";
+      OS << "{ \"pid\":1, \"tid\":0, \"ph\":\"X\", \"ts\":" << StartUs
+         << ", \"dur\":" << DurUs << ", \"name\":\"" << escapeString(E.Name)
+         << "\", \"args\":{ \"detail\":\"" << escapeString(E.Detail)
+         << "\"} },\n";
     }
 
     // Emit totals by section name as additional "thread" events, sorted from
     // longest one.
     int Tid = 1;
     std::vector<NameAndCountAndDurationType> SortedTotals;
     SortedTotals.reserve(CountAndTotalPerName.size());
-    for (const auto &E : CountAndTotalPerName) {
+    for (const auto &E : CountAndTotalPerName)
       SortedTotals.emplace_back(E.getKey(), E.getValue());
-    }
-    std::sort(SortedTotals.begin(), SortedTotals.end(),
-              [](const NameAndCountAndDurationType &A,
-                 const NameAndCountAndDurationType &B) {
-                return A.second.second > B.second.second;
-              });
+
+    llvm::sort(SortedTotals.begin(), SortedTotals.end(),
+               [](const NameAndCountAndDurationType &A,
+                  const NameAndCountAndDurationType &B) {
+                 return A.second.second > B.second.second;
+               });
     for (const auto &E : SortedTotals) {
       auto DurUs = duration_cast<microseconds>(E.second.second).count();
       auto Count = CountAndTotalPerName[E.first].first;
-      *OS << "{ \"pid\":1, \"tid\":" << Tid << ", \"ph\":\"X\", \"ts\":" << 0
-          << ", \"dur\":" << DurUs << ", \"name\":\"Total "
-          << escapeString(E.first) << "\", \"args\":{ \"count\":" << Count
-          << ", \"avg ms\":" << (DurUs / Count / 1000) << "} },\n";
+      OS << "{ \"pid\":1, \"tid\":" << Tid << ", \"ph\":\"X\", \"ts\":" << 0
+         << ", \"dur\":" << DurUs << ", \"name\":\"Total "
+         << escapeString(E.first) << "\", \"args\":{ \"count\":" << Count
+         << ", \"avg ms\":" << (DurUs / Count / 1000) << "} },\n";
       ++Tid;
     }
 
     // Emit metadata event with process name.
-    *OS << "{ \"cat\":\"\", \"pid\":1, \"tid\":0, \"ts\":0, \"ph\":\"M\", "
-           "\"name\":\"process_name\", \"args\":{ \"name\":\"clang\" } }\n";
-    *OS << "] }\n";
+    OS << "{ \"cat\":\"\", \"pid\":1, \"tid\":0, \"ts\":0, \"ph\":\"M\", "
+          "\"name\":\"process_name\", \"args\":{ \"name\":\"clang\" } }\n";
+    OS << "] }\n";
   }
 
-  std::vector<Entry> Stack;
-  std::vector<Entry> Entries;
+  SmallVector<Entry, 16> Stack;
+  SmallVector<Entry, 128> Entries;
   StringMap<CountAndDurationType> CountAndTotalPerName;
   time_point<steady_clock> StartTime;
 };
@@ -162,7 +170,7 @@ void timeTraceProfilerCleanup() {
   TimeTraceProfilerInstance = nullptr;
 }
 
-void timeTraceProfilerWrite(std::unique_ptr<raw_pwrite_stream> &OS) {
+void timeTraceProfilerWrite(raw_pwrite_stream &OS) {
   assert(TimeTraceProfilerInstance != nullptr &&
          "Profiler object can't be null");
   TimeTraceProfilerInstance->Write(OS);