Rdar 30961871 metrics mark 2

include/swift/Basic/Statistic.h

@@ -13,7 +13,9 @@
 #ifndef SWIFT_BASIC_STATISTIC_H
 #define SWIFT_BASIC_STATISTIC_H
 
+#include "llvm/ADT/SmallString.h"
 #include "llvm/ADT/Statistic.h"
+#include "swift/Basic/Timer.h"
 
 #define SWIFT_FUNC_STAT                                                 \
   do {                                                                  \
@@ -22,4 +24,85 @@
     ++FStat;                                                            \
   } while (0)
 
+// Helper class designed to consolidate reporting of LLVM statistics and timers
+// across swift compilations that typically invoke many drivers, each running
+// many frontends. Additionally collects some cheap "always-on" statistics,
+// beyond those that are (compile-time) parametrized by -DLLVM_ENABLE_STATS
+// (LLVM's stats are global and involve some amount of locking and mfences).
+//
+// Assumes it's given a process name and target name (the latter used as
+// decoration for its self-timer), and a directory to collect stats into, then:
+//
+//  - On construction:
+//    - Calls llvm::EnableStatistics(/*PrintOnExit=*/false)
+//    - Calls swift::enableCompilationTimers()
+//    - Starts an llvm::NamedRegionTimer for this process
+//
+//  - On destruction:
+//    - Add any standard always-enabled stats about the process as a whole
+//    - Opens $dir/stats-$timestamp-$name-$random.json for writing
+//    - Calls llvm::PrintStatisticsJSON(ostream) and/or its own writer
+//
+// Generally we make one of these per-process: either early in the life of the
+// driver, or early in the life of the frontend.
+
+namespace swift {
+
+class UnifiedStatsReporter {
+
+public:
+  struct AlwaysOnDriverCounters
+  {
+    size_t NumDriverJobsRun;
+    size_t NumDriverJobsSkipped;
+
+    size_t DriverDepCascadingTopLevel;
+    size_t DriverDepCascadingDynamic;
+    size_t DriverDepCascadingNominal;
+    size_t DriverDepCascadingMember;
+    size_t DriverDepCascadingExternal;
+
+    size_t DriverDepTopLevel;
+    size_t DriverDepDynamic;
+    size_t DriverDepNominal;
+    size_t DriverDepMember;
+    size_t DriverDepExternal;
+  };
+
+  struct AlwaysOnFrontendCounters
+  {
+    size_t NumSILGenFunctions;
+    size_t NumSILGenVtables;
+    size_t NumSILGenWitnessTables;
+    size_t NumSILGenDefaultWitnessTables;
+    size_t NumSILGenGlobalVariables;
+
+    size_t NumSILOptFunctions;
+    size_t NumSILOptVtables;
+    size_t NumSILOptWitnessTables;
+    size_t NumSILOptDefaultWitnessTables;
+    size_t NumSILOptGlobalVariables;
+  };
+
+private:
+  SmallString<128> Filename;
+  std::unique_ptr<llvm::NamedRegionTimer> Timer;
+
+  std::unique_ptr<AlwaysOnDriverCounters> DriverCounters;
+  std::unique_ptr<AlwaysOnFrontendCounters> FrontendCounters;
+
+  void publishAlwaysOnStatsToLLVM();
+  void printAlwaysOnStatsAndTimers(llvm::raw_ostream &OS);
+
+public:
+  UnifiedStatsReporter(StringRef ProgramName,
+                       StringRef TargetName,
+                       StringRef Directory);
+  ~UnifiedStatsReporter();
+
+  AlwaysOnDriverCounters &getDriverCounters();
+  AlwaysOnFrontendCounters &getFrontendCounters();
+};
+
+}
 #endif // SWIFT_BASIC_STATISTIC_H

include/swift/Driver/Compilation.h

@@ -21,6 +21,7 @@
 #include "swift/Driver/Util.h"
 #include "swift/Basic/ArrayRefView.h"
 #include "swift/Basic/LLVM.h"
+#include "swift/Basic/Statistic.h"
 #include "llvm/ADT/DenseSet.h"
 #include "llvm/ADT/StringRef.h"
 #include "llvm/Support/Chrono.h"
@@ -134,6 +135,9 @@ class Compilation {
   /// execute.
   bool ShowDriverTimeCompilation;
 
+  /// When non-null, record various high-level counters to this.
+  std::unique_ptr<UnifiedStatsReporter> Stats;
+
   /// When true, dumps information about why files are being scheduled to be
   /// rebuilt.
   bool ShowIncrementalBuildDecisions = false;
@@ -156,7 +160,8 @@ class Compilation {
               bool EnableIncrementalBuild = false,
               bool SkipTaskExecution = false,
               bool SaveTemps = false,
-              bool ShowDriverTimeCompilation = false);
+              bool ShowDriverTimeCompilation = false,
+              std::unique_ptr<UnifiedStatsReporter> Stats = nullptr);
   ~Compilation();
 
   ArrayRefView<std::unique_ptr<const Job>, const Job *, Compilation::unwrap>

include/swift/Driver/DependencyGraph.h

@@ -33,6 +33,8 @@ namespace llvm {
 
 namespace swift {
 
+class UnifiedStatsReporter;
+
 /// The non-templated implementation of DependencyGraph.
 ///
 /// \see DependencyGraph
@@ -65,12 +67,14 @@ class DependencyGraphImpl {
   class MarkTracerImpl {
     class Entry;
     llvm::DenseMap<const void *, SmallVector<Entry, 4>> Table;
+    UnifiedStatsReporter *Stats;
 
     friend class DependencyGraphImpl;
   protected:
-    MarkTracerImpl();
+    explicit MarkTracerImpl(UnifiedStatsReporter *Stats);
     ~MarkTracerImpl();
-
+    void countStatsForNodeMarking(const OptionSet<DependencyKind> &Kind,
+                                  bool Cascading) const;
     void printPath(raw_ostream &out, const void *item,
                    llvm::function_ref<void(const void *)> printItem) const;
   };
@@ -223,7 +227,8 @@ class DependencyGraph : public DependencyGraphImpl {
   /// This is intended to be a debugging aid.
   class MarkTracer : public MarkTracerImpl {
   public:
-    MarkTracer() = default;
+    explicit MarkTracer(UnifiedStatsReporter *Stats)
+      : MarkTracerImpl(Stats) {}
 
     /// Dump the path that led to \p node.
     void printPath(raw_ostream &out, T node,

include/swift/Frontend/FrontendOptions.h

@@ -192,6 +192,9 @@ class FrontendOptions {
   /// \sa swift::SharedTimer
   bool DebugTimeCompilation = false;
 
+  /// The path to which we should output statistics files.
+  std::string StatsOutputDir;
+
   /// Indicates whether function body parsing should be delayed
   /// until the end of all files.
   bool DelayedFunctionBodyParsing = false;

include/swift/Option/Options.td

@@ -191,6 +191,9 @@ def save_temps : Flag<["-"], "save-temps">,
 def driver_time_compilation : Flag<["-"], "driver-time-compilation">,
   Flags<[NoInteractiveOption,DoesNotAffectIncrementalBuild]>,
   HelpText<"Prints the total time it took to execute all compilation tasks">;
+def stats_output_dir: Separate<["-"], "stats-output-dir">,
+  Flags<[FrontendOption, HelpHidden]>,
+  HelpText<"Directory to write unified compilation-statistics files to">;
 
 def emit_dependencies : Flag<["-"], "emit-dependencies">,
   Flags<[FrontendOption, NoInteractiveOption, DoesNotAffectIncrementalBuild]>,

lib/Basic/CMakeLists.txt

@@ -83,6 +83,7 @@ add_swift_library(swiftBasic STATIC
   Program.cpp
   QuotedString.cpp
   SourceLoc.cpp
+  Statistic.cpp
   StringExtras.cpp
   TaskQueue.cpp
   ThreadSafeRefCounted.cpp

lib/Basic/Statistic.cpp

@@ -0,0 +1,191 @@
+//===--- Statistic.cpp - Swift unified stats reporting --------------------===//
+//
+// This source file is part of the Swift.org open source project
+//
+// Copyright (c) 2017 Apple Inc. and the Swift project authors
+// Licensed under Apache License v2.0 with Runtime Library Exception
+//
+// See https://swift.org/LICENSE.txt for license information
+// See https://swift.org/CONTRIBUTORS.txt for the list of Swift project authors
+//
+//===----------------------------------------------------------------------===//
+
+#include "swift/Basic/Statistic.h"
+#include "swift/Driver/DependencyGraph.h"
+#include "swift/SIL/SILModule.h"
+#include "llvm/Support/FileSystem.h"
+#include "llvm/Support/Path.h"
+#include "llvm/Support/Process.h"
+#include "llvm/Support/raw_ostream.h"
+#include <chrono>
+
+namespace swift {
+using namespace llvm;
+using namespace llvm::sys;
+
+static std::string
+makeFileName(StringRef ProcessName) {
+  std::string tmp;
+  raw_string_ostream stream(tmp);
+  auto now = std::chrono::system_clock::now();
+  stream << "stats"
+         << "-" << now.time_since_epoch().count()
+         << "-" << ProcessName
+         << "-" << Process::GetRandomNumber()
+         << ".json";
+  return stream.str();
+}
+
+UnifiedStatsReporter::UnifiedStatsReporter(StringRef ProgramName,
+                                           StringRef TargetName,
+                                           StringRef Directory)
+  : Filename(Directory),
+    Timer(make_unique<NamedRegionTimer>(TargetName, "Building Target",
+                                        ProgramName, "Running Program"))
+{
+  path::append(Filename, makeFileName(ProgramName));
+  EnableStatistics(/*PrintOnExit=*/false);
+  SharedTimer::enableCompilationTimers();
+}
+
+UnifiedStatsReporter::AlwaysOnDriverCounters &
+UnifiedStatsReporter::getDriverCounters()
+{
+  if (!DriverCounters)
+    DriverCounters = make_unique<AlwaysOnDriverCounters>();
+  return *DriverCounters;
+}
+
+UnifiedStatsReporter::AlwaysOnFrontendCounters &
+UnifiedStatsReporter::getFrontendCounters()
+{
+  if (!FrontendCounters)
+    FrontendCounters = make_unique<AlwaysOnFrontendCounters>();
+  return *FrontendCounters;
+}
+
+#define PUBLISH_STAT(C,TY,NAME)                               \
+  do {                                                        \
+    static Statistic Stat = {TY, #NAME, #NAME, {0}, false};   \
+    Stat += (C).NAME;                                         \
+  } while(0)
+
+void
+UnifiedStatsReporter::publishAlwaysOnStatsToLLVM() {
+  if (FrontendCounters) {
+    auto &C = getFrontendCounters();
+    PUBLISH_STAT(C, "SILModule", NumSILGenFunctions);
+    PUBLISH_STAT(C, "SILModule", NumSILGenVtables);
+    PUBLISH_STAT(C, "SILModule", NumSILGenWitnessTables);
+    PUBLISH_STAT(C, "SILModule", NumSILGenDefaultWitnessTables);
+    PUBLISH_STAT(C, "SILModule", NumSILGenGlobalVariables);
+
+    PUBLISH_STAT(C, "SILModule", NumSILOptFunctions);
+    PUBLISH_STAT(C, "SILModule", NumSILOptVtables);
+    PUBLISH_STAT(C, "SILModule", NumSILOptWitnessTables);
+    PUBLISH_STAT(C, "SILModule", NumSILOptDefaultWitnessTables);
+    PUBLISH_STAT(C, "SILModule", NumSILOptGlobalVariables);
+  }
+  if (DriverCounters) {
+    auto &C = getDriverCounters();
+    PUBLISH_STAT(C, "Driver", NumDriverJobsRun);
+    PUBLISH_STAT(C, "Driver", NumDriverJobsSkipped);
+
+    PUBLISH_STAT(C, "Driver", DriverDepCascadingTopLevel);
+    PUBLISH_STAT(C, "Driver", DriverDepCascadingDynamic);
+    PUBLISH_STAT(C, "Driver", DriverDepCascadingNominal);
+    PUBLISH_STAT(C, "Driver", DriverDepCascadingMember);
+    PUBLISH_STAT(C, "Driver", DriverDepCascadingExternal);
+
+    PUBLISH_STAT(C, "Driver", DriverDepTopLevel);
+    PUBLISH_STAT(C, "Driver", DriverDepDynamic);
+    PUBLISH_STAT(C, "Driver", DriverDepNominal);
+    PUBLISH_STAT(C, "Driver", DriverDepMember);
+    PUBLISH_STAT(C, "Driver", DriverDepExternal);
+  }
+}
+
+#define PRINT_STAT(OS,DELIM,C,TY,NAME)                   \
+  do {                                                   \
+    OS << DELIM << "\t\"" TY "." #NAME "\": " << C.NAME; \
+    delim = ",\n";                                       \
+  } while(0)
+
+void
+UnifiedStatsReporter::printAlwaysOnStatsAndTimers(raw_ostream &OS) {
+  // Adapted from llvm::PrintStatisticsJSON
+  OS << "{\n";
+  const char *delim = "";
+  if (FrontendCounters) {
+    auto &C = getFrontendCounters();
+    PRINT_STAT(OS, delim, C, "SILModule", NumSILGenFunctions);
+    PRINT_STAT(OS, delim, C, "SILModule", NumSILGenVtables);
+    PRINT_STAT(OS, delim, C, "SILModule", NumSILGenWitnessTables);
+    PRINT_STAT(OS, delim, C, "SILModule", NumSILGenDefaultWitnessTables);
+    PRINT_STAT(OS, delim, C, "SILModule", NumSILGenGlobalVariables);
+
+    PRINT_STAT(OS, delim, C, "SILModule", NumSILOptFunctions);
+    PRINT_STAT(OS, delim, C, "SILModule", NumSILOptVtables);
+    PRINT_STAT(OS, delim, C, "SILModule", NumSILOptWitnessTables);
+    PRINT_STAT(OS, delim, C, "SILModule", NumSILOptDefaultWitnessTables);
+    PRINT_STAT(OS, delim, C, "SILModule", NumSILOptGlobalVariables);
+  }
+  if (DriverCounters) {
+    auto &C = getDriverCounters();
+    PRINT_STAT(OS, delim, C, "Driver", NumDriverJobsRun);
+    PRINT_STAT(OS, delim, C, "Driver", NumDriverJobsSkipped);
+
+    PRINT_STAT(OS, delim, C, "Driver", DriverDepCascadingTopLevel);
+    PRINT_STAT(OS, delim, C, "Driver", DriverDepCascadingDynamic);
+    PRINT_STAT(OS, delim, C, "Driver", DriverDepCascadingNominal);
+    PRINT_STAT(OS, delim, C, "Driver", DriverDepCascadingMember);
+    PRINT_STAT(OS, delim, C, "Driver", DriverDepCascadingExternal);
+
+    PRINT_STAT(OS, delim, C, "Driver", DriverDepTopLevel);
+    PRINT_STAT(OS, delim, C, "Driver", DriverDepDynamic);
+    PRINT_STAT(OS, delim, C, "Driver", DriverDepNominal);
+    PRINT_STAT(OS, delim, C, "Driver", DriverDepMember);
+    PRINT_STAT(OS, delim, C, "Driver", DriverDepExternal);
+  }
+  // Print timers.
+  TimerGroup::printAllJSONValues(OS, delim);
+  OS << "\n}\n";
+  OS.flush();
+}
+
+UnifiedStatsReporter::~UnifiedStatsReporter()
+{
+  // NB: Timer needs to be Optional<> because it needs to be destructed early;
+  // LLVM will complain about double-stopping a timer if you tear down a
+  // NamedRegionTimer after printing all timers. The printing routines were
+  // designed with more of a global-scope, run-at-process-exit in mind, which
+  // we're repurposing a bit here.
+  Timer.reset();
+
+  std::error_code EC;
+  raw_fd_ostream ostream(Filename, EC, fs::F_Append | fs::F_Text);
+  if (EC)
+    return;
+
+  // We change behaviour here depending on whether -DLLVM_ENABLE_STATS and/or
+  // assertions were on in this build; this is somewhat subtle, but turning on
+  // all stats for all of LLVM and clang is a bit more expensive and intrusive
+  // than we want to be in release builds.
+  //
+  //  - If enabled: we copy all of our "always-on" local stats into LLVM's
+  //    global statistics list, and ask LLVM to manage the printing of them.
+  //
+  //  - If disabled: we still have our "always-on" local stats to write, and
+  //    LLVM's global _timers_ were still enabled (they're runtime-enabled, not
+  //    compile-time) so we sequence printing our own stats and LLVM's timers
+  //    manually.
+
+#if !defined(NDEBUG) || defined(LLVM_ENABLE_STATS)
+  publishAlwaysOnStatsToLLVM();
+  PrintStatisticsJSON(ostream);
+#else
+  printAlwaysOnStatsAndTimers(ostream);
+#endif
+}
+
+} // namespace swift