diff --git a/docs/OptimizerCountersAnalysis.md b/docs/OptimizerCountersAnalysis.md new file mode 100644 index 0000000000000..b6763fcd408a4 --- /dev/null +++ b/docs/OptimizerCountersAnalysis.md @@ -0,0 +1,348 @@ +# Optimizer Counter Analysis + +It is possible possible by means of providing some special command-line +options to ask the Swift compiler to produce different statistics about +the optimizer counters. Optimizer counters are most typically counters +representing different aspects of a SIL representation for a Swift module +being compiled, e.g. the number of SIL basic blocks or instructions. +These counters may also reveal some details about transformations +and optimizations performed on SIL, e.g. the duration of an optimization +or how much memory was consumed by the compiler. Therefore having the +information about the changes of optimizer counters over time allows for +analysis of changes to the SIL representation during the compilation. + +This document describes how you collect and analyze the counters produced by +the optimizer of the Swift compiler. This analysis is useful if you need to get +a detailed insight into the optimizer passes, their effect on the SIL code, +compile times, compiler's memory consumption, etc. For example, you can find +out which optimization passes or phases of optimization produce most new SIL +instructions or delete most SIL functions. + +## Table of contents + +- [Optimizer Counter Analysis](#optimizer-counter-analysis) + - [Table of contents](#table-of-contents) + - [Which optimizer counters are available for recording](#which-optimizer-counters-are-available-for-recording) + - [How and when the optimizer counters are collected and recorded](#how-and-when-the-optimizer-counters-are-collected-and-recorded) + - [Differences between different modes of optimizer counters collection](#differences-between-different-modes-of-optimizer-counters-collection) + - [Module level counters](#module-level-counters) + - [Function level counters](#function-level-counters) + - [Instruction level counters](#instruction-level-counters) + - [Configuring which counters changes should be recorded](#configuring-which-counters-changes-should-be-recorded) + - [On-line and off-line processing of optimizer counters](#on-line-and-off-line-processing-of-optimizer-counters) + - [Specifying where the optimizer counters should be stored](#specifying-where-the-optimizer-counters-should-be-stored) + - [The format of the recorded optimizer counters](#the-format-of-the-recorded-optimizer-counters) + - [Storing the produced statistics into a database](#storing-the-produced-statistics-into-a-database) + - [The database schema for counters](#the-database-schema-for-counters) + - [Analyzing collected counters using SQL](#analyzing-collected-counters-using-sql) + - [Examples of interesting SQL queries](#examples-of-interesting-sql-queries) + - [Compute aggregate times for each optimization pass/transformation](#compute-aggregate-times-for-each-optimization-passtransformation) + - [Which pass created/deleted most functions?](#which-pass-createddeleted-most-functions) + - [Which pass at which optimization pipeline stage created/deleted most functions?](#which-pass-at-which-optimization-pipeline-stage-createddeleted-most-functions) + - [Which pass created/removed most instructions?](#which-pass-createdremoved-most-instructions) + - [Which pass at which stage created/removed most instructions?](#which-pass-at-which-stage-createdremoved-most-instructions) + - [Which functions were changed most by which stage when it comes to the instruction counts](#which-functions-were-changed-most-by-which-stage-when-it-comes-to-the-instruction-counts) + - [Get the number of instructions at the beginning and at the end of the optimization pipeline for each function](#get-the-number-of-instructions-at-the-beginning-and-at-the-end-of-the-optimization-pipeline-for-each-function) + - [Show functions which have the biggest size at the end of the optimization pipeline](#show-functions-which-have-the-biggest-size-at-the-end-of-the-optimization-pipeline) + - [Which optimization pipeline stage took most time?](#which-optimization-pipeline-stage-took-most-time) + - [Which stage added/removed most instructions (in term of deltas)?](#which-stage-addedremoved-most-instructions-in-term-of-deltas) + + +## Which optimizer counters are available for recording + +The following statistics can be recorded: + + * For SILFunctions: the number of SIL basic blocks for each SILFunction, the + number of SIL instructions, the number of SILInstructions of a specific + kind (e.g. a number of alloc_ref instructions) + + * For SILModules: the number of SIL basic blocks in the SILModule, the number + of SIL instructions, the number of SILFunctions, the number of + SILInstructions of a specific kind (e.g. a number of alloc_ref + instructions) the amount of memory used by the compiler. + +## How and when the optimizer counters are collected and recorded + +The pass manager of the SIL optimizer invokes special hooks before and after it +executes any optimization transformation (often called an optimization pass). + +The hook checks if there are any changes of counter values since the last time +it was invoked. If there are any changes, then the counters are re-computed. +They are first re-computed for SILFunctions and then for the SILModule being +compiled. The re-computation algorithm is trying to be incremental and fast by +re-computing only the minimal amount of counters instead of scanning the whole +SILModule every time. + +Those counters that are changed are reported if they satisfy different +filtering conditions, which are configurable. For example, you may want to see +only counters that have changed by more than 50% since last time. +Alternatively, you may want to log as many counters as possible, in which case +they will be logged on every invocation of the hook. + +If there were no changes to the counters that satisfy the filtering conditions, +those changes would not be logged. This means that the final set of logged +changes may be incomplete, i.e. it would not reflect all changes that happened +to those counters. + +## Differences between different modes of optimizer counters collection + +You can collect optimizer counters at different levels of granularity depending +on your needs. The granularity also affects the amount of recorded data that +will be produced, because the amount of recorded data grows if you decide to +collect more fine-grained counters. + +### Module level counters +The most coarse-grained counters are the module level counters, which are +enabled by using `-Xllvm -sil-stats-modules` command-line option. They are +usually logged only if a given optimizer counter changed a lot for the whole +SILModule, which does not happen that often, because most optimization passes +perform just very small transformations on a single function and thus do not +significantly change any module-wide counters. + +### Function level counters +The next level of granularity are SILFunction counters, which are enabled by +using `-Xllvm -sil-stats-functions` command-line option. They track statistics +for SILFunctions. Every SILFunction has its own set of these counters. +Obviously, interesting changes to these counters happen more often than to the +module-wide counters. + +### Instruction level counters +The finest level of granularity are SILInstruction counters, which are enabled +by using `-Xllvm -sil-stats-only-instructions` command-line option. You can use +them to e.g. collect statistics about how many specific SIL instructions are +used by a given SILFunction or a SILModule. For example, you can count how many +`alloc_ref` instructions occur in a given SILFunction or SILModule. If you are +interested in collecting the stats only for some specific SIL instructions, you +can use a comma-separated list of instructions as a value of the option, +e.g. `-Xllvm -sil-stats-only-instructions=alloc_ref,alloc_stack`. If you need to +collect stats about all kinds of SIL instructions, you can use this syntax: +`-Xllvm -sil-stats-only-instructions=all`. + +## Configuring which counters changes should be recorded + +The user has a possibility to configure a number of thresholds, which control +what needs to be recorded. Many of those thresholds are formulated for the +deltas, e.g. the delta should be more than 50%. + +The value of the delta for a given old and new values of a counter are computed +using the following simple formula: + + `delta = 100% * (new_value - old_value)/old_value` + +So, a delta basically reflects how big is the change of the counter value +when expressed as a percentage of the old value. + +TBD Provide more information about different command-line options for +configuring the thresholds. + +## On-line and off-line processing of optimizer counters + +As explained above, some of the counters filtering happens on-line at +compile-time already. If this is enough for your purposes, you can use them "as +is". + +But in many cases, you may want to perform more complex analysis of the +collected counters, e.g. you may want to aggregate them by the optimization +pass or by a stage of the optimization pipeline, etc. This is not directly +supported by the on-line filtering mode. Instead, you can record all the +interesting counters and then post-process it off-line by first storing them +into a SQLite database by means if a special utility and then using the regular +SQL queries to perform any kind of analysis and aggregation that you may need. + +## Specifying where the optimizer counters should be stored + +By default, all the collected statistics are written to the +standard error. + +But it is possible to write into a custom file by specifying the following +command-line option: + + `-Xllvm -sil-stats-output-file=your_file_name` + +## The format of the recorded optimizer counters + +The counters are recorded using a simple CSV (comma separated value) format. +Each line represents a single counter value or a counter value change. + +For counter value updates, the CSV line looks like this: + * `Kind, CounterName, StageName, TransformName, + TransformPassNumber, DeltaValue, OldCounterValue, + NewCounterValue, Duration, Symbol` + +And for counter stats it looks like this: + * `Kind, CounterName, StageName, TransformName, + TransformPassNumber, CounterValue, Duration, Symbol` + + where the names used above have the following meaning: + +* `Kind` is one of `function`, `module`, `function_history`. + * `function` and + `module` correspond directly to the module-level and function-level counters + * `function_history` corresponds to the verbose mode of function + counters collection, when changes to the SILFunction counters are logged + unconditionally, without any on-line filtering. +* `CounterName` is typically one of `block`, `inst`, `function`, `memory`, + or `inst_instruction_name` if you collect counters for specific kinds of SIL + instructions. +* `Symbol` is e.g. the name of a function +* `StageName` is the name of the current optimizer pipeline stage +* `TransformName` is the name of the current optimizer transformation/pass +* `Duration` is the duration of the transformation +* `TransformPassNumber` is the optimizer pass number. It is useful if you + want to reproduce the result later using + `-Xllvm -sil-opt-pass-count -Xllvm TransformPassNumber` + +## Storing the produced statistics into a database + +To store the set of produced counters into a database, you can use the +following command: + +`utils/optimizer_counters_to_sql.py csv_file_with_counters your_database.db` + +## The database schema for counters + +The database uses a very simple self-explaining schema: + +```sql +CREATE TABLE Counters( + Id INTEGER PRIMARY KEY AUTOINCREMENT, + Stage TEXT NOT NULL, + Transform TEXT NOT NULL, + Kind TEXT, + Counter TEXT NOT NULL, + PassNum INT NOT NULL, + Delta NUMBER, + Old INT, + New INT, + Duration INT, + Symbol TEXT NOT NULL DEFAULT ''); +``` + +## Analyzing collected counters using SQL + +First, you need to connect to your database, so that you can issue SQL queries. +This can be accomplished e.g. by the following command: + + `sqlite3 your_database.db` + +After executing this command, you will be presented with a SQLite command +prompt and you can start entering SQL queries. Each query should end with +a semicolon. + +### Examples of interesting SQL queries + +SQL gives you a lot of freedom to perform different kinds of analysis. Below +you can find some examples of typical queries, which you can use "as is" or as +a basis for formulating more complex queries. + +#### Compute aggregate times for each optimization pass/transformation + +```sql +select C.Transform, sum(C.Duration) +from Counters C +where C.counter = 'inst' and C.kind = 'module' +group by C.Transform; +``` + +#### Which pass created/deleted most functions? +```sql +select C.Transform, sum(C.Delta) +from Counters C +where C.counter = 'functions' and C.kind = 'module' +group by C.Transform; +``` + +#### Which pass at which optimization pipeline stage created/deleted most functions? +```sql +select C.Stage, C.Transform, sum(C.Delta) +from Counters C where C.counter = 'functions' and C.kind = 'module' +group by C.Stage, C.Transform; +``` + +#### Which pass created/removed most instructions? + +```sql +# Sort by biggest changes +select C.Transform, sum(C.Delta) +from Counters C where C.counter = 'inst' and C.kind = 'module' +group by C.Transform +order by abs(sum(C.Delta)); +``` + +#### Which pass at which stage created/removed most instructions? +```sql +# Sort by biggest changes +select C.Stage, C.Transform, sum(C.Delta) +from Counters C where C.counter = 'inst' and C.kind = 'module' +group by C.Stage, C.Transform +order by abs(sum(C.Delta)); +``` + +#### Which functions were changed most by which stage when it comes to the instruction counts + +```sql +select C.Stage, min(C.Old), max(C.Old), Symbol +from Counters C where C.counter = 'inst' and C.kind = 'function_history' +group by C.Symbol, C.Stage +having min(C.Old) <> max(C.Old) +order by abs(max(C.Old)-min(C.Old)); +``` + +#### Get the number of instructions at the beginning and at the end of the optimization pipeline for each function +```sql +select MinOld.Id, MinOld.Old, MaxOld.Id, MaxOld.Old, MinOld.Symbol +from +( + select C.Id, C.Old, C.Symbol + from Counters C where C.counter = 'inst' and C.kind = 'function_history' + group by C.Symbol + having C.Id = max(Id) +) as MaxOld, +(select C.Id, C.Old, C.Symbol + from Counters C + where C.counter = 'inst' and C.kind = 'function_history' + group by C.Symbol + having C.Id = min(Id) +) as MinOld +where MinOld.Symbol == MaxOld.Symbol; +``` + +#### Show functions which have the biggest size at the end of the optimization pipeline +```sql +select MinOld.Id, MinOld.Old, MaxOld.Id, MaxOld.Old, MinOld.Symbol +from +( + select C.Id, C.Old, C.Symbol + from Counters C + where C.counter = 'inst' and C.kind = 'function_history' + group by C.Symbol + having C.Id = max(Id) +) as MaxOld, +( + select C.Id, C.Old, C.Symbol + from Counters C + where C.counter = 'inst' and C.kind = 'function_history' + group by C.Symbol + having C.Id = min(Id) +) as MinOld +where MinOld.Symbol == MaxOld.Symbol +order by MaxOld.Old; +``` + +#### Which optimization pipeline stage took most time? +```sql +select sum(Duration), Stage +from Counters C +where C.counter = 'inst' and C.kind = 'module' +group by Stage +order by sum(C.Duration); +``` + +#### Which stage added/removed most instructions (in term of deltas)? +```sql +select sum(Delta), Stage +from Counters C where C.counter = 'inst' and C.kind = 'module' +group by Stage +order by sum(C.Delta); +``` + diff --git a/include/swift/SIL/SILInstruction.h b/include/swift/SIL/SILInstruction.h index 9fe88adec8f00..c32b4a62ed21f 100644 --- a/include/swift/SIL/SILInstruction.h +++ b/include/swift/SIL/SILInstruction.h @@ -68,6 +68,12 @@ enum class SILInstructionKind : std::underlying_type::type { #include "SILNodes.def" }; +/// Map SILInstruction's mnemonic name to its SILInstructionKind. +SILInstructionKind getSILInstructionKind(StringRef InstName); + +/// Map SILInstructionKind to a corresponding SILInstruction name. +StringRef getSILInstructionName(SILInstructionKind Kind); + /// This is the root class for all instructions that can be used as the contents /// of a Swift SILBasicBlock. class SILInstruction : public ValueBase,public llvm::ilist_node{ @@ -96,10 +102,21 @@ class SILInstruction : public ValueBase,public llvm::ilist_node{ /// SILClonerWithScope instead. void setDebugScope(SILBuilder &B, const SILDebugScope *DS); + /// Total number of created and deleted SILInstructions. + /// It is used only for collecting the compiler statistics. + static int NumCreatedInstructions; + static int NumDeletedInstructions; + protected: SILInstruction(ValueKind Kind, SILDebugLocation DebugLoc, SILType Ty = SILType()) - : ValueBase(Kind, Ty), ParentBB(0), Location(DebugLoc) {} + : ValueBase(Kind, Ty), ParentBB(0), Location(DebugLoc) { + NumCreatedInstructions++; + } + + ~SILInstruction() { + NumDeletedInstructions++; + } public: /// Instructions should be allocated using a dedicated instruction allocation @@ -335,6 +352,16 @@ class SILInstruction : public ValueBase,public llvm::ilist_node{ /// Verify that all operands of this instruction have compatible ownership /// with this instruction. void verifyOperandOwnership() const; + + /// Get the number of created SILInstructions. + static int getNumCreatedInstructions() { + return NumCreatedInstructions; + } + + /// Get the number of deleted SILInstructions. + static int getNumDeletedInstructions() { + return NumDeletedInstructions; + } }; /// Returns the combined behavior of \p B1 and \p B2. diff --git a/include/swift/SIL/SILValue.h b/include/swift/SIL/SILValue.h index e7057664b5330..bc7d869f799d3 100644 --- a/include/swift/SIL/SILValue.h +++ b/include/swift/SIL/SILValue.h @@ -785,6 +785,12 @@ inline llvm::raw_ostream &operator<<(llvm::raw_ostream &OS, SILValue V) { return OS; } +/// Map a SILValue mnemonic name to its ValueKind. +ValueKind getSILValueKind(StringRef Name); + +/// Map ValueKind to a corresponding mnemonic name. +StringRef getSILValueName(ValueKind Kind); + } // end namespace swift diff --git a/include/swift/SILOptimizer/Analysis/Analysis.def b/include/swift/SILOptimizer/Analysis/Analysis.def index 0dd8d468febcf..8cbf23cf37ef0 100644 --- a/include/swift/SILOptimizer/Analysis/Analysis.def +++ b/include/swift/SILOptimizer/Analysis/Analysis.def @@ -36,6 +36,7 @@ ANALYSIS(Escape) ANALYSIS(InductionVariable) ANALYSIS(Loop) ANALYSIS(LoopRegion) +ANALYSIS(OptimizerStats) ANALYSIS(PostDominance) ANALYSIS(PostOrder) ANALYSIS(RCIdentity) diff --git a/include/swift/SILOptimizer/PassManager/PassManager.h b/include/swift/SILOptimizer/PassManager/PassManager.h index 5a09d81e7cff6..0324d10af84da 100644 --- a/include/swift/SILOptimizer/PassManager/PassManager.h +++ b/include/swift/SILOptimizer/PassManager/PassManager.h @@ -211,9 +211,16 @@ class SILPassManager { /// owned by the pass manager. Analysis passes will be kept. void resetAndRemoveTransformations(); - // Sets the name of the current optimization stage used for debugging. + /// \brief Set the name of the current optimization stage. + /// + /// This is useful for debugging. void setStageName(llvm::StringRef NextStage = ""); + /// \brief Get the name of the current optimization stage. + /// + /// This is useful for debugging. + StringRef getStageName() const; + /// D'tor. ~SILPassManager(); diff --git a/include/swift/SILOptimizer/Utils/OptimizerStatsUtils.h b/include/swift/SILOptimizer/Utils/OptimizerStatsUtils.h new file mode 100644 index 0000000000000..9920d7652fb86 --- /dev/null +++ b/include/swift/SILOptimizer/Utils/OptimizerStatsUtils.h @@ -0,0 +1,41 @@ +//===--- OptimizerStatsUtils.h - Utils for collecting stats --*- C++ ---*-===// +// +// This source file is part of the Swift.org open source project +// +// Copyright (c) 2014 - 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 +// +//===----------------------------------------------------------------------===// + +#ifndef SWIFT_OPTIMIZER_STATS_UTILS_H +#define SWIFT_OPTIMIZER_STATS_UTILS_H + +namespace swift { +class SILModule; +class SILTransform; +class SILPassManager; + +/// Updates SILModule stats before executing the transform \p Transform. +/// +/// \param M SILModule to be processed +/// \param Transform the SIL transformation that was just executed +/// \param PM the PassManager being used +void updateSILModuleStatsBeforeTransform(SILModule &M, SILTransform *Transform, + SILPassManager &PM, int PassNumber); + +/// Updates SILModule stats after finishing executing the +/// transform \p Transform. +/// +/// \param M SILModule to be processed +/// \param Transform the SIL transformation that was just executed +/// \param PM the PassManager being used +void updateSILModuleStatsAfterTransform(SILModule &M, SILTransform *Transform, + SILPassManager &PM, int PassNumber, + int Duration); + +} // end namespace swift + +#endif diff --git a/lib/SIL/SILInstruction.cpp b/lib/SIL/SILInstruction.cpp index ef0d9fc54f69b..72e37d2356701 100644 --- a/lib/SIL/SILInstruction.cpp +++ b/lib/SIL/SILInstruction.cpp @@ -168,6 +168,29 @@ void SILInstruction::dropAllReferences() { } } +// Initialize the static members of SILInstruction. +int SILInstruction::NumCreatedInstructions = 0; +int SILInstruction::NumDeletedInstructions = 0; + +/// Map a SILInstruction name to its SILInstructionKind. +SILInstructionKind swift::getSILInstructionKind(StringRef InstName) { + auto Kind = getSILValueKind(InstName); + if (Kind >= ValueKind::First_SILInstruction && + Kind <= ValueKind::Last_SILInstruction) + return SILInstructionKind(Kind); + +#ifdef NDEBUG + llvm::errs() << "Unknown SIL instruction name\n"; + abort(); +#endif + llvm_unreachable("Unknown SIL insruction name"); +} + +/// Map SILInstructionKind to a corresponding SILInstruction name. +StringRef swift::getSILInstructionName(SILInstructionKind Kind) { + return getSILValueName(ValueKind(Kind)); +} + namespace { class InstructionDestroyer : public SILInstructionVisitor { diff --git a/lib/SIL/SILPrinter.cpp b/lib/SIL/SILPrinter.cpp index 0da4db1e7cea7..3ff1f37b0ca97 100644 --- a/lib/SIL/SILPrinter.cpp +++ b/lib/SIL/SILPrinter.cpp @@ -826,14 +826,7 @@ class SILPrinter : public SILVisitor { } void printInstOpCode(SILInstruction *I) { - // If we have a SILInstruction, print out the opcode. - switch (SILInstructionKind(I->getKind())) { -#define INST(Id, Parent, TextualName, MemoryBehavior, ReleasingBehavior) \ - case SILInstructionKind::Id: \ - *this << #TextualName " "; \ - break; -#include "swift/SIL/SILNodes.def" - } + *this << getSILValueName(I->getKind()) << " "; } void print(SILValue V) { diff --git a/lib/SIL/SILValue.cpp b/lib/SIL/SILValue.cpp index d9cb62f42784b..6ed5a0eabef69 100644 --- a/lib/SIL/SILValue.cpp +++ b/lib/SIL/SILValue.cpp @@ -182,3 +182,40 @@ ValueOwnershipKind SILValue::getOwnershipKind() const { sil::ValueOwnershipKindClassifier Classifier; return Classifier.visit(const_cast(Value)); } + +/// Map a SILValue mnemonic name to its ValueKind. +ValueKind swift::getSILValueKind(StringRef Name) { +#define INST(Id, Parent, TextualName, MemoryBehavior, ReleasingBehavior) \ + if (Name == #TextualName) \ + return ValueKind::Id; + +#define VALUE(Id, Parent) \ + if (Name == #Id) \ + return ValueKind::Id; + +#include "swift/SIL/SILNodes.def" + +#ifdef NDEBUG + llvm::errs() + << "Unknown SILValue name\n"; + abort(); +#endif + llvm_unreachable("Unknown SILValue name"); +} + +/// Map ValueKind to a corresponding mnemonic name. +StringRef swift::getSILValueName(ValueKind Kind) { + switch (Kind) { +#define INST(Id, Parent, TextualName, MemoryBehavior, ReleasingBehavior) \ + case ValueKind::Id: \ + return #TextualName; \ + break; + +#define VALUE(Id, Parent) \ + case ValueKind::Id: \ + return #Id; \ + break; + +#include "swift/SIL/SILNodes.def" + } +} diff --git a/lib/SILOptimizer/PassManager/PassManager.cpp b/lib/SILOptimizer/PassManager/PassManager.cpp index a0140a40ee1cf..5aa0f81275c11 100644 --- a/lib/SILOptimizer/PassManager/PassManager.cpp +++ b/lib/SILOptimizer/PassManager/PassManager.cpp @@ -20,6 +20,7 @@ #include "swift/SILOptimizer/Analysis/FunctionOrder.h" #include "swift/SILOptimizer/PassManager/PrettyStackTrace.h" #include "swift/SILOptimizer/PassManager/Transforms.h" +#include "swift/SILOptimizer/Utils/OptimizerStatsUtils.h" #include "llvm/ADT/DenseMap.h" #include "llvm/ADT/Statistic.h" #include "llvm/ADT/StringSwitch.h" @@ -316,6 +317,8 @@ void SILPassManager::runPassOnFunction(SILFunctionTransform *SFT, return; } + updateSILModuleStatsBeforeTransform(F->getModule(), SFT, *this, NumPassesRun); + CurrentPassHasInvalidated = false; if (SILPrintPassName) @@ -338,8 +341,8 @@ void SILPassManager::runPassOnFunction(SILFunctionTransform *SFT, assert(analysesUnlocked() && "Expected all analyses to be unlocked!"); Mod->removeDeleteNotificationHandler(SFT); + auto Delta = (std::chrono::system_clock::now() - StartTime).count(); if (SILPrintPassTime) { - auto Delta = (std::chrono::system_clock::now() - StartTime).count(); llvm::dbgs() << Delta << " (" << SFT->getName() << "," << F->getName() << ")\n"; } @@ -352,6 +355,9 @@ void SILPassManager::runPassOnFunction(SILFunctionTransform *SFT, F->dump(getOptions().EmitVerboseSIL); } + updateSILModuleStatsAfterTransform(F->getModule(), SFT, *this, NumPassesRun, + Delta); + // Remember if this pass didn't change anything. if (!CurrentPassHasInvalidated) completedPasses.set((size_t)SFT->getPassKind()); @@ -440,6 +446,8 @@ void SILPassManager::runModulePass(SILModuleTransform *SMT) { SMT->injectPassManager(this); SMT->injectModule(Mod); + updateSILModuleStatsBeforeTransform(*Mod, SMT, *this, NumPassesRun); + CurrentPassHasInvalidated = false; if (SILPrintPassName) @@ -460,8 +468,8 @@ void SILPassManager::runModulePass(SILModuleTransform *SMT) { Mod->removeDeleteNotificationHandler(SMT); assert(analysesUnlocked() && "Expected all analyses to be unlocked!"); + auto Delta = (std::chrono::system_clock::now() - StartTime).count(); if (SILPrintPassTime) { - auto Delta = (std::chrono::system_clock::now() - StartTime).count(); llvm::dbgs() << Delta << " (" << SMT->getName() << ",Module)\n"; } @@ -474,6 +482,8 @@ void SILPassManager::runModulePass(SILModuleTransform *SMT) { printModule(Mod, Options.EmitVerboseSIL); } + updateSILModuleStatsAfterTransform(*Mod, SMT, *this, NumPassesRun, Delta); + if (Options.VerifyAll && (CurrentPassHasInvalidated || !SILVerifyWithoutInvalidation)) { Mod->verify(); @@ -608,6 +618,10 @@ void SILPassManager::setStageName(llvm::StringRef NextStage) { StageName = NextStage; } +StringRef SILPassManager::getStageName() const { + return StageName; +} + const SILOptions &SILPassManager::getOptions() const { return Mod->getOptions(); } diff --git a/lib/SILOptimizer/Utils/CMakeLists.txt b/lib/SILOptimizer/Utils/CMakeLists.txt index c5cb4a0d09738..50eb3247350fd 100644 --- a/lib/SILOptimizer/Utils/CMakeLists.txt +++ b/lib/SILOptimizer/Utils/CMakeLists.txt @@ -9,6 +9,7 @@ set(UTILS_SOURCES Utils/LoadStoreOptUtils.cpp Utils/Local.cpp Utils/LoopUtils.cpp + Utils/OptimizerStatsUtils.cpp Utils/PerformanceInlinerUtils.cpp Utils/SILInliner.cpp Utils/SILSSAUpdater.cpp diff --git a/lib/SILOptimizer/Utils/OptimizerStatsUtils.cpp b/lib/SILOptimizer/Utils/OptimizerStatsUtils.cpp new file mode 100644 index 0000000000000..6030a07f7170d --- /dev/null +++ b/lib/SILOptimizer/Utils/OptimizerStatsUtils.cpp @@ -0,0 +1,967 @@ +//===-- OptimizerStatsUtils.cpp - Utils for collecting stats -*- C++ ---*-===// +// +// This source file is part of the Swift.org open source project +// +// Copyright (c) 2014 - 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 +// +//===----------------------------------------------------------------------===// +/// +/// \file +/// +/// This file implements collection and dumping of statistics about SILModules, +/// SILFunctions and memory consumption during the execution of SIL +/// optimization pipelines. +/// +/// The following statistics are collected: +/// - For SILFunctions: the number of SIL basic blocks, the number of SIL +/// instructions +/// +/// - For SILModules: the number of SIL basic blocks, the number of SIL +/// instructions, the number of SILFunctions, the amount of memory used by the +/// compiler. +/// +/// By default, any collection of statistics is disabled to avoid affecting +/// compile times. +/// +/// One can enable the collection of statistics and dumping of these statistics +/// for the whole SILModule and/or for SILFunctions. +/// +/// To reduce the amount of produced data, one can set thresholds in such a way +/// that changes in the statistics are only reported if the delta between the +/// old and the new values are at least X%. The deltas are computed using the +/// following formula: +/// Delta = (NewValue - OldValue) / OldValue +/// +/// Thresholds provide a simple way to perform a simple filtering of the +/// collected statistics during the compilation. But if there is a need for a +/// more complex analysis of collected data (e.g. aggregation by a pipeline +/// stage or by the type of a transformation), it is often better to dump +/// as much data as possible into a file using e.g. `-sil-stats-dump-all +/// -sil-stats-modules -sil-stats-functions` and then e.g. use the helper scripts +/// to store the collected data into a database and then perform complex queries +/// on it. Many kinds of analysis can be then formulated pretty easily as SQL +/// queries. +/// +/// The output format is a set of CSV (comma separated values) lines. Each lines +/// represents one counter or one counter change. +/// +/// For counter updates it looks like this: +/// Kind, CounterName, StageName, TransformName, TransformPassNumber, +/// DeltaValue, OldCounterValue, NewCounterValue, Duration, Symbol +/// +/// For counter updates it looks like this: +/// Kind, CounterName, StageName, TransformName, TransformPassNumber, +/// CounterValue, Duration, Symbol +/// +/// where Kind is one of "function", "module", "function_history", +/// CounterName is one of "block", "inst", "function", "memory", +/// Symbol is e.g. the name of a function. +/// StageName and TransformName are the names of the current optimizer +/// pipeline stage and current transform. +/// Duration is the duration of the transformation. +//===----------------------------------------------------------------------===// + +#include "llvm/Support/CommandLine.h" +#include "llvm/Support/FileSystem.h" +#include "llvm/Support/Process.h" +#include "swift/SIL/SILValue.h" +#include "swift/SIL/SILVisitor.h" +#include "swift/SILOptimizer/Analysis/Analysis.h" +#include "swift/SILOptimizer/PassManager/PassManager.h" +#include "swift/SILOptimizer/PassManager/Transforms.h" +#include "swift/SILOptimizer/Utils/OptimizerStatsUtils.h" +using namespace swift; + +namespace { + +/// The total number of different kinds of SILInstructions. +constexpr unsigned SILInstructionsNum = int(ValueKind::Last_SILInstruction) + 1; + +/// A set of counters, one per SILInstruction kind. +using InstructionCounts = SmallVector; + +/// A helper type to parse a comma separated list of SIL instruction names +/// provided as argument of the -sil-stats-only-instructions options. +class StatsOnlyInstructionsOpt { + /// If ComputeInstCounts[i] is non-zero, this kind of SILInstruction should be + /// tracked. + InstructionCounts ComputeInstCounts; + /// The number of different kinds of SILInstructions to be tracked. + int InstCountsNum = 0; + +public: + StatsOnlyInstructionsOpt() : ComputeInstCounts(SILInstructionsNum) {} + + void operator=(const std::string &Val) { + if (Val.empty()) + return; + if (Val == "all") { + for (auto &Inst : ComputeInstCounts) { + Inst = 1; + } + InstCountsNum = ComputeInstCounts.size(); + return; + } + SmallVector statsInstNames; + StringRef(Val).split(statsInstNames, ',', -1, false); + for (auto instName : statsInstNames) { + // Check if it is a known instruction. + auto Kind = getSILInstructionKind(instName); + if (!ComputeInstCounts[int(Kind)] ){ + ComputeInstCounts[int(Kind)] = 1; + InstCountsNum++; + } + } + } + + bool shouldComputeInstCount(SILInstructionKind Kind) const { + return ComputeInstCounts[int(Kind)] != 0; + } + + int getInstCountsNum() const { + return InstCountsNum; + } +}; + +StatsOnlyInstructionsOpt StatsOnlyInstructionsOptLoc; + +/// Use this option like -Xllvm -sil-stats-only-instructions=strong_retain,alloc_stack +/// If you need to track all kinds of SILInstructions, you can use +/// -sil-stats-only-instructions=all +llvm::cl::opt> + StatsOnlyInstructions( + "sil-stats-only-instructions", + llvm::cl::desc( + "Comma separated list of SIL insruction names, whose stats " + "should be collected"), + llvm::cl::Hidden, llvm::cl::ZeroOrMore, + llvm::cl::value_desc("instruction name"), + llvm::cl::location(StatsOnlyInstructionsOptLoc), + llvm::cl::ValueRequired); + +/// Dump as much statistics as possible, ignore any thresholds. +llvm::cl::opt SILStatsDumpAll( + "sil-stats-dump-all", llvm::cl::init(false), + llvm::cl::desc("Dump all SIL module and SIL function stats")); + +/// Dump statistics about the SILModule. +llvm::cl::opt SILStatsModules( + "sil-stats-modules", llvm::cl::init(false), + llvm::cl::desc("Enable computation of statistics for SIL modules")); + +/// Dump statistics about SILFunctions. +llvm::cl::opt SILStatsFunctions( + "sil-stats-functions", llvm::cl::init(false), + llvm::cl::desc("Enable computation of statistics for SIL functions")); + +/// The name of the output file for optimizer counters. +llvm::cl::opt SILStatsOutputFile( + "sil-stats-output-file", llvm::cl::init(""), + llvm::cl::desc("The name of the output file for optimizer counters")); + +/// A threshold in percents for the SIL basic block counters. +llvm::cl::opt BlockCountDeltaThreshold( + "sil-stats-block-count-delta-threshold", llvm::cl::init(1), + llvm::cl::desc( + "Threshold for reporting changed basic block count numbers")); + +/// A threshold in percents for the SIL instructions counters. +llvm::cl::opt InstCountDeltaThreshold( + "sil-stats-inst-count-delta-threshold", llvm::cl::init(1), + llvm::cl::desc( + "Threshold for reporting changed instruction count numbers")); + +/// A threshold in percents for the SIL functions counters. +llvm::cl::opt FunctionCountDeltaThreshold( + "sil-stats-function-count-delta-threshold", llvm::cl::init(1), + llvm::cl::desc("Threshold for reporting changed function count numbers")); + +/// A threshold in percents for the counters of memory used by the compiler. +llvm::cl::opt UsedMemoryDeltaThreshold( + "sil-stats-used-memory-delta-threshold", llvm::cl::init(5), + llvm::cl::desc("Threshold for reporting changed memory usage numbers")); + +llvm::cl::opt UsedMemoryMinDeltaThreshold( + "sil-stats-used-memory-min-threshold", llvm::cl::init(1), + llvm::cl::desc("Min hreshold for reporting changed memory usage numbers")); + +/// A threshold in percents for the basic blocks counter inside a SILFunction. +/// Has effect only if it is used together with -sil-stats-functions. +llvm::cl::opt FuncBlockCountDeltaThreshold( + "sil-stats-func-block-count-delta-threshold", llvm::cl::init(200), + llvm::cl::desc("Threshold for reporting changed basic block count numbers " + "for a function")); + +/// A minimal threshold (in number of basic blocks) for the basic blocks counter +/// inside a SILFunction. Only functions with more basic blocks than this +/// threshold are reported. Has effect only if it is used together with +/// -sil-stats-functions. +llvm::cl::opt FuncBlockCountMinThreshold( + "sil-stats-func-block-count-min-threshold", llvm::cl::init(50), + llvm::cl::desc( + "Min threshold for reporting changed basic block count numbers " + "for a function")); + +/// A threshold in percents for the SIL instructions counter inside a +/// SILFunction. Has effect only if it is used together with +/// -sil-stats-functions. +llvm::cl::opt FuncInstCountDeltaThreshold( + "sil-stats-func-inst-count-delta-threshold", llvm::cl::init(200), + llvm::cl::desc("Threshold for reporting changed instruction count numbers " + "for a function")); + +/// A minimal threshold (in number of instructions) for the SIL instructions +/// counter inside a SILFunction. Only functions with more instructions than +/// this threshold are reported. Has effect only if it is used together with +/// -sil-stats-functions. +llvm::cl::opt FuncInstCountMinThreshold( + "sil-stats-func-inst-count-min-threshold", llvm::cl::init(300), + llvm::cl::desc( + "Min threshold for reporting changed instruction count numbers " + "for a function")); + +/// Track only statistics for a function with a given name. +/// Has effect only if it is used together with -sil-stats-functions. +llvm::cl::opt StatsOnlyFunctionName( + "sil-stats-only-function", llvm::cl::init(""), + llvm::cl::desc("Function name, whose stats should be tracked")); + +/// Track only statistics for a function whose name contains a given substring. +/// Has effect only if it is used together with -sil-stats-functions. +llvm::cl::opt StatsOnlyFunctionsNamePattern( + "sil-stats-only-functions", llvm::cl::init(""), + llvm::cl::desc( + "Pattern of a function name, whose stats should be tracked")); + +/// Stats for a SIL function. +struct FunctionStat { + int BlockCount = 0; + int InstCount = 0; + /// Instruction counts per SILInstruction kind. + InstructionCounts InstCounts; + + FunctionStat(SILFunction *F); + FunctionStat() : InstCounts(SILInstructionsNum) {} + + void print(llvm::raw_ostream &stream) const { + stream << "FunctionStat(" + << "blocks = " << BlockCount << ", Inst = " << InstCount << ")\n"; + } + + bool operator==(const FunctionStat &rhs) const { + return BlockCount == rhs.BlockCount && InstCount == rhs.InstCount; + } + + bool operator!=(const FunctionStat &rhs) const { return !(*this == rhs); } + + void dump() { print(llvm::errs()); } +}; + +/// Stats a single SIL module. +struct ModuleStat { + /// Total number of SILFunctions in the current SILModule. + int FunctionCount = 0; + /// Total number of SILBasicBlocks in the current SILModule. + int BlockCount = 0; + /// Total number of SILInstructions in the current SILModule. + int InstCount = 0; + /// Total amount of memory used by the compiler. + int UsedMemory = 0; + /// Total number of SILInstructions created since the beginning of the current + /// compilation. + int CreatedInstCount = 0; + /// Total number of SILInstructions deleted since the beginning of the current + /// compilation. + int DeletedInstCount = 0; + /// Instruction counts per SILInstruction kind. + InstructionCounts InstCounts; + + ModuleStat() : InstCounts(SILInstructionsNum) {} + + /// Add the stats for a given function to the total module stats. + void addFunctionStat(FunctionStat &Stat) { + BlockCount += Stat.BlockCount; + InstCount += Stat.InstCount; + ++FunctionCount; + if (!StatsOnlyInstructionsOptLoc.getInstCountsNum()) + return; + for (unsigned i : indices(InstCounts)) { + InstCounts[i] += Stat.InstCounts[i]; + } + } + + /// Subtract the stats for a given function from total module stats. + void subFunctionStat(FunctionStat &Stat) { + BlockCount -= Stat.BlockCount; + InstCount -= Stat.InstCount; + --FunctionCount; + if (!StatsOnlyInstructionsOptLoc.getInstCountsNum()) + return; + for (unsigned i : indices(InstCounts)) { + InstCounts[i] -= Stat.InstCounts[i]; + } + } + + /// Add the stats about current memory usage. + void addMemoryStat() { + UsedMemory = llvm::sys::Process::GetMallocUsage(); + } + + /// Add the stats about created and deleted instructions. + void addCreatedAndDeletedInstructionsStat() { + CreatedInstCount = SILInstruction::getNumCreatedInstructions(); + DeletedInstCount = SILInstruction::getNumDeletedInstructions(); + } + + void print(llvm::raw_ostream &stream) const { + stream << "ModuleStat(functions = " << FunctionCount + << ", blocks = " << BlockCount << ", Inst = " << InstCount + << ", UsedMemory = " << UsedMemory / (1024 * 1024) + << ", CreatedInst = " << CreatedInstCount + << ", DeletedInst = " << DeletedInstCount + << ")\n"; + } + + void dump() { print(llvm::errs()); } + + bool operator==(const ModuleStat &rhs) const { + return FunctionCount == rhs.FunctionCount && BlockCount == rhs.BlockCount && + InstCount == rhs.InstCount && UsedMemory == rhs.UsedMemory; + } + + bool operator!=(const ModuleStat &rhs) const { return !(*this == rhs); } +}; + +// A helper type to collect the stats about the number of instructions and basic +// blocks. +struct InstCountVisitor : SILVisitor { + int BlockCount = 0; + int InstCount = 0; + InstructionCounts &InstCounts; + + InstCountVisitor(InstructionCounts &InstCounts) : InstCounts(InstCounts) {} + + int getBlockCount() const { + return BlockCount; + } + + int getInstCount() const { + return InstCount; + } + + void visitSILBasicBlock(SILBasicBlock *BB) { + ++BlockCount; + SILVisitor::visitSILBasicBlock(BB); + } + + void visitSILFunction(SILFunction *F) { + SILVisitor::visitSILFunction(F); + } + + void visitValueBase(ValueBase *V) {} + +#define INST(Id, Parent, TextualName, MemBehavior, ReleasingBehavior) \ + void visit##Id(Id *I) { \ + ++InstCount; \ + ++InstCounts[int(I->getKind())]; \ + } +#include "swift/SIL/SILNodes.def" +}; + +/// A helper type to store different parameters related to the current transform. +class TransformationContext { + /// SILModule being processed. + SILModule &M; + /// The pass manager being used. + SILPassManager &PM; + /// The transformation that was/will be performed. + SILTransform *Transform; + /// The time it took to perform the transformation. + int Duration; + /// The pass number in the optimizer pipeline. + int PassNumber; + +public: + TransformationContext(SILModule &M, SILPassManager &PM, + SILTransform *Transform, int PassNumber, int Duration) + : M(M), PM(PM), Transform(Transform), Duration(Duration), + PassNumber(PassNumber) {} + + int getPassNumber() const { + return PassNumber; + } + + int getDuration() const { + return Duration; + } + + StringRef getTransformId() const { + return Transform->getID(); + } + + StringRef getStageName() const { + return PM.getStageName(); + } + + SILModule &getModule() { + return M; + } + + SILPassManager &getPassManager() { + return PM; + } +}; + +/// Aggregated statistics for the whole SILModule and all SILFunctions belonging +/// to it. +class AccumulatedOptimizerStats { + using FunctionStats = llvm::DenseMap; + + /// Current stats for each function. + FunctionStats FuncStats; + /// Current stats for the module. + ModuleStat ModStat; + +public: + FunctionStat &getFunctionStat(const SILFunction *F) { + return FuncStats[F]; + } + + ModuleStat &getModuleStat() { + return ModStat; + } + + void deleteFunctionStat(SILFunction *F) { + FuncStats.erase(F); + } +}; + +/// A helper class to repesent the module stats as an analysis, +/// so that it is preserved across multiple passes. +class OptimizerStatsAnalysis : public SILAnalysis { + SILModule &M; + /// The actual cache holding all the statistics. + std::unique_ptr Cache; + + /// Sets of functions changed, deleted or added since the last + /// computation of statistics. These sets are used to avoid complete + /// re-computation of the stats for the whole module. Instead only + /// re-compute the stats for the changed functions, which is much + /// faster. + SmallVector InvalidatedFuncs; + SmallVector DeletedFuncs; + SmallVector AddedFuncs; + +public: + OptimizerStatsAnalysis(SILModule *M) + : SILAnalysis(AnalysisKind::OptimizerStats), M(*M), Cache(nullptr) {} + + static bool classof(const SILAnalysis *S) { + return S->getKind() == AnalysisKind::OptimizerStats; + } + + /// Invalidate all information in this analysis. + virtual void invalidate() override { + // This analysis is never invalidated, because it just used + // to store the statistics. + } + + /// Invalidate all of the information for a specific function. + virtual void invalidate(SILFunction *F, InvalidationKind K) override { + InvalidatedFuncs.push_back(F); + } + + /// Notify the analysis about a newly created function. + virtual void notifyAddFunction(SILFunction *F) override { + AddedFuncs.push_back(F); + } + + /// Notify the analysis about a function which will be deleted from the + /// module. + virtual void notifyDeleteFunction(SILFunction *F) override { + DeletedFuncs.push_back(F); + }; + + /// Notify the analysis about changed witness or vtables. + virtual void invalidateFunctionTables() override { + } + + + SILModule &getModule() const { + return M; + } + + /// Get the collected statistics for a function. + FunctionStat &getFunctionStat(const SILFunction *F) { + if (!Cache) + Cache = llvm::make_unique(); + + return Cache->getFunctionStat(F); + } + + /// Get the collected statistics for a module. + ModuleStat &getModuleStat() { + if (!Cache) + Cache = llvm::make_unique(); + + return Cache->getModuleStat(); + } + + /// Update module stats after running the Transform. + void updateModuleStats(TransformationContext &Ctx); +}; + +class NewLineInserter { + bool isNewline = true; + +public: + NewLineInserter() {} + StringRef get() { + StringRef result = isNewline ? "\n" : ""; + isNewline = false; + return result; + } +}; + +/// The output stream to be used for writing the collected statistics. +/// Use the unique_ptr to ensure that the file is properly closed upon +/// exit. +std::unique_ptr> + stats_output_stream; + +/// Return the output streamm to be used for logging the collected statistics. +llvm::raw_ostream &stats_os() { + // Initialize the stream if it is not initialized yet. + if (!stats_output_stream) { + // If there is user-defined output file name, use it. + if (!SILStatsOutputFile.empty()) { + // Try to open the file. + std::error_code EC; + llvm::raw_fd_ostream *fd_stream = new llvm::raw_fd_ostream( + SILStatsOutputFile, EC, llvm::sys::fs::OpenFlags::F_Text); + if (!fd_stream->has_error() && !EC) { + stats_output_stream = {fd_stream, + [](llvm::raw_ostream *d) { delete d; }}; + return *stats_output_stream.get(); + } + fd_stream->clear_error(); + llvm::errs() << SILStatsOutputFile << " : " << EC.message() << "\n"; + delete fd_stream; + } + // Otherwise use llvm::errs() as output. No need to destroy it at the end. + stats_output_stream = {&llvm::errs(), [](llvm::raw_ostream *d) {}}; + } + return *stats_output_stream.get(); +} + +/// A helper function to dump the counter value. +void printCounterValue(StringRef Kind, StringRef CounterName, int CounterValue, + StringRef Symbol, TransformationContext &Ctx) { + stats_os() << Kind; + stats_os() << ", "; + + stats_os() << CounterName; + stats_os() << ", "; + + stats_os() << Ctx.getStageName(); + stats_os() << ", "; + + stats_os() << Ctx.getTransformId(); + stats_os() << ", "; + + stats_os() << Ctx.getPassNumber(); + stats_os() << ", "; + + stats_os() << CounterValue; + stats_os() << ", "; + + stats_os() << Ctx.getDuration(); + stats_os() << ", "; + + stats_os() << Symbol; + stats_os() << "\n"; +} + +/// A helper function to dump the change of the counter value. +void printCounterChange(StringRef Kind, StringRef CounterName, double Delta, + int OldValue, int NewValue, TransformationContext &Ctx, + StringRef Symbol = "") { + stats_os() << Kind; + stats_os() << ", "; + + stats_os() << CounterName; + stats_os() << ", "; + + stats_os() << Ctx.getStageName(); + stats_os() << ", "; + + stats_os() << Ctx.getTransformId(); + stats_os() << ", "; + + stats_os() << Ctx.getPassNumber(); + stats_os() << ", "; + + llvm::format_provider::format(Delta, stats_os(), "f8"); + stats_os() << ", "; + + stats_os() << OldValue; + stats_os() << ", "; + + stats_os() << NewValue; + stats_os() << ", "; + + stats_os() << Ctx.getDuration(); + stats_os() << ", "; + + stats_os() << Symbol; + stats_os() << "\n"; +} + +/// Check if a function name matches the pattern provided by the user. +bool isMatchingFunction(SILFunction *F, bool shouldHaveNamePattern = false) { + auto FuncName = F->getName(); + // Is it an exact string match? + if (!StatsOnlyFunctionName.empty()) + return F->getName() == StatsOnlyFunctionName; + + // Does the name contain a user-defined substring? + if (!StatsOnlyFunctionsNamePattern.empty()) { + return FuncName.contains(StatsOnlyFunctionsNamePattern); + } + + return shouldHaveNamePattern ? true : false; +} + +/// Compute the delta between the old and new values. +/// Return it as a percent value. +double computeDelta(int Old, int New) { + return 100.0 * (Old ? ((New - Old) * 1.0 / Old) : 0.0); +} + +/// Returns true if it is a first time we collect data for a given counter. +/// This is the case if the old value is 0 and the new one is something +/// different, i.e. we didn't have any statistics about it. +bool isFirstTimeData(int Old, int New) { + return Old == 0 && New != Old; +} + +/// Dump statistics for a SILFunction. It is only used if a user asked to +/// produce detailed stats about transformations of SILFunctions. This +/// information is dumped unconditionally, for each transformation that changed +/// the function in any form. No thresholds are taken into account. +/// +/// \param Stat statistics computed now, after the run of the transformation +/// \param Ctx transformation context to be used +void processFuncStatHistory(SILFunction *F, FunctionStat &Stat, + TransformationContext &Ctx) { + if (!SILStatsFunctions) + return; + + if (!SILStatsDumpAll && !isMatchingFunction(F, /*shouldHaveNamePattern*/ true)) + return; + + printCounterValue("function_history", "block", Stat.BlockCount, F->getName(), + Ctx); + printCounterValue("function_history", "inst", Stat.InstCount, F->getName(), + Ctx); + + /// Dump collected instruction counts. + if (!StatsOnlyInstructionsOptLoc.getInstCountsNum()) + return; + + for (int i = 0, e = SILInstructionsNum; i < e; ++i) { + if (!Stat.InstCounts[i]) + continue; + SILInstructionKind Kind = SILInstructionKind(i); + if (!StatsOnlyInstructionsOptLoc.shouldComputeInstCount(Kind)) + continue; + std::string CounterName = "inst_"; + CounterName += getSILInstructionName(Kind); + printCounterValue("function_history", CounterName, Stat.InstCounts[i], + F->getName(), Ctx); + } +} + +/// Process SILFunction's statistics changes. +/// +/// \param OldStat statistics computed last time +/// \param NewStat statistics computed now, after the run of the transformation +/// \param Ctx transformation context to be used +void processFuncStatsChanges(SILFunction *F, FunctionStat &OldStat, + FunctionStat &NewStat, + TransformationContext &Ctx) { + processFuncStatHistory(F, NewStat, Ctx); + + if (!SILStatsFunctions && !SILStatsDumpAll) + return; + + if (OldStat == NewStat) + return; + + if ((!StatsOnlyFunctionsNamePattern.empty() || + !StatsOnlyFunctionName.empty()) && + !isMatchingFunction(F)) + return; + + // Compute deltas. + double DeltaBlockCount = computeDelta(OldStat.BlockCount, NewStat.BlockCount); + double DeltaInstCount = computeDelta(OldStat.InstCount, NewStat.InstCount); + + NewLineInserter nl; + + // TODO: handle cases where a function got smaller. + if ((SILStatsDumpAll && + (DeltaBlockCount != 0.0 || OldStat.BlockCount == 0)) || + (abs(DeltaBlockCount) > FuncBlockCountDeltaThreshold && + OldStat.BlockCount > FuncBlockCountMinThreshold)) { + stats_os() << nl.get(); + printCounterChange("function", "block", DeltaBlockCount, OldStat.BlockCount, + NewStat.BlockCount, Ctx, F->getName()); + } + + if ((SILStatsDumpAll && (DeltaInstCount != 0.0 || OldStat.InstCount == 0)) || + (abs(DeltaInstCount) > FuncInstCountDeltaThreshold && + OldStat.InstCount > FuncInstCountMinThreshold)) { + stats_os() << nl.get(); + printCounterChange("function", "inst", DeltaInstCount, OldStat.InstCount, + NewStat.InstCount, Ctx, F->getName()); + } +} + +/// Process SILModule's statistics changes. +/// +/// \param OldStat statistics computed last time +/// \param NewStat statistics computed now, after the run of the transformation +/// \param Ctx transformation context to be used +void processModuleStatsChanges(ModuleStat &OldStat, ModuleStat &NewStat, + TransformationContext &Ctx) { + if (!SILStatsModules && !SILStatsDumpAll) + return; + + // Bail if no changes. + if (OldStat == NewStat) + return; + + // Compute deltas. + double DeltaBlockCount = computeDelta(OldStat.BlockCount, NewStat.BlockCount); + double DeltaInstCount = computeDelta(OldStat.InstCount, NewStat.InstCount); + double DeltaFunctionCount = + computeDelta(OldStat.FunctionCount, NewStat.FunctionCount); + double DeltaUsedMemory = computeDelta(OldStat.UsedMemory, NewStat.UsedMemory); + + NewLineInserter nl; + + // Print delta for blocks only if it is above a threshold or we are asked to + // dump all changes. + if ((SILStatsDumpAll && + (DeltaBlockCount != 0.0 || + isFirstTimeData(OldStat.BlockCount, NewStat.BlockCount))) || + (abs(DeltaBlockCount) > BlockCountDeltaThreshold)) { + stats_os() << nl.get(); + printCounterChange("module", "block", DeltaBlockCount, OldStat.BlockCount, + NewStat.BlockCount, Ctx); + } + + // Print delta for instructions only if it is above a threshold or we are + // asked to dump all changes. + if ((SILStatsDumpAll && + (DeltaInstCount != 0.0 || + isFirstTimeData(OldStat.InstCount, NewStat.InstCount))) || + (abs(DeltaInstCount) > InstCountDeltaThreshold)) { + stats_os() << nl.get(); + printCounterChange("module", "inst", DeltaInstCount, OldStat.InstCount, + NewStat.InstCount, Ctx); + } + + // Print delta for functions only if it is above a threshold or we are + // asked to dump all changes. + if ((SILStatsDumpAll && + (DeltaFunctionCount != 0.0 || + isFirstTimeData(OldStat.FunctionCount, NewStat.FunctionCount))) || + (abs(DeltaFunctionCount) > FunctionCountDeltaThreshold)) { + stats_os() << nl.get(); + printCounterChange("module", "functions", DeltaFunctionCount, + OldStat.FunctionCount, NewStat.FunctionCount, Ctx); + } + + // Print delta for the used memory only if it is above a threshold or we are + // asked to dump all changes. + if ((SILStatsDumpAll && + (abs(DeltaUsedMemory) > UsedMemoryMinDeltaThreshold || + isFirstTimeData(OldStat.UsedMemory, NewStat.UsedMemory))) || + (abs(DeltaUsedMemory) > UsedMemoryDeltaThreshold)) { + stats_os() << nl.get(); + printCounterChange("module", "memory", DeltaUsedMemory, OldStat.UsedMemory, + NewStat.UsedMemory, Ctx); + } + + + if (SILStatsDumpAll) { + // Dump stats about the number of created and deleted instructions. + auto DeltaCreatedInstCount = + computeDelta(OldStat.CreatedInstCount, NewStat.CreatedInstCount); + auto DeltaDeletedInstCount = + computeDelta(OldStat.DeletedInstCount, NewStat.DeletedInstCount); + if (DeltaCreatedInstCount != 0.0 || + isFirstTimeData(OldStat.CreatedInstCount, NewStat.CreatedInstCount)) + printCounterChange("module", "created_inst", DeltaCreatedInstCount, + OldStat.CreatedInstCount, NewStat.CreatedInstCount, + Ctx); + if (DeltaDeletedInstCount != 0.0 || + isFirstTimeData(OldStat.DeletedInstCount, NewStat.DeletedInstCount)) + printCounterChange("module", "deleted_inst", DeltaDeletedInstCount, + OldStat.DeletedInstCount, NewStat.DeletedInstCount, + Ctx); + } + + /// Dump collected instruction counts. + if (!StatsOnlyInstructionsOptLoc.getInstCountsNum()) + return; + + for (int i = 0, e = SILInstructionsNum; i < e; ++i) { + // Do not print anything, if there is no change. + if (OldStat.InstCounts[i] == NewStat.InstCounts[i]) + continue; + SILInstructionKind Kind = SILInstructionKind(i); + if (!StatsOnlyInstructionsOptLoc.shouldComputeInstCount(Kind)) + continue; + SmallString<64> CounterName("inst_"); + CounterName += getSILInstructionName(Kind); + auto DeltaCounterKindCount = + computeDelta(OldStat.InstCounts[i], NewStat.InstCounts[i]); + printCounterChange("module", CounterName, DeltaCounterKindCount, + OldStat.InstCounts[i], NewStat.InstCounts[i], Ctx); + } +} + +/// Update the stats for a module after a SIL transform has been performed. +void OptimizerStatsAnalysis::updateModuleStats(TransformationContext &Ctx) { + assert(&getModule() == &Ctx.getModule()); + + auto &ModStat = getModuleStat(); + auto OldModStat = ModStat; + ModuleStat NewModStat; + + // First, collect statistics that require scanning SILFunctions. + if (OldModStat.FunctionCount == 0) { + // This is the first time the stats are computed for the module. + // Iterate over all functions in the module and compute the stats. + for (auto &F : M) { + auto &FuncStat = getFunctionStat(&F); + FunctionStat NewFuncStat(&F); + processFuncStatHistory(&F, NewFuncStat, Ctx); + // Update function stats. + FuncStat = NewFuncStat; + // Update module stats. + NewModStat.addFunctionStat(NewFuncStat); + } + } else { + // Go only over functions that were changed since the last computation. + // These are the functions that got invalidated, removed or added. + // + // If no functions were changed by the last executed transformation, then + // the sets of invalidated, deleted and added functions will be empty and + // no FunctionStats will be updated. + // + // FIXME: As a result, the current implementation does not record the fact + // about performing a given transformation on a given function, if the + // function was not changed during the transformation. This reduced the + // amount of recorded information, but makes the history of transformations + // on a given function incomplete. If this ever becomes an issue, we can + // record all transformations, even if they do not change anything. + NewModStat = OldModStat; + + // Process modified functions. + while (!InvalidatedFuncs.empty()) { + auto *F = InvalidatedFuncs.back(); + InvalidatedFuncs.pop_back(); + auto &FuncStat = getFunctionStat(F); + auto OldFuncStat = FuncStat; + FunctionStat NewFuncStat(F); + processFuncStatsChanges(F, OldFuncStat, NewFuncStat, Ctx); + NewModStat.subFunctionStat(OldFuncStat); + NewModStat.addFunctionStat(NewFuncStat); + FuncStat = NewFuncStat; + } + + // Process deleted functions. + while (!DeletedFuncs.empty()) { + auto *F = DeletedFuncs.back(); + DeletedFuncs.pop_back(); + auto &FuncStat = getFunctionStat(F); + auto OldFuncStat = FuncStat; + FunctionStat NewFuncStat; + processFuncStatsChanges(F, OldFuncStat, NewFuncStat, Ctx); + NewModStat.subFunctionStat(OldFuncStat); + Cache->deleteFunctionStat(F); + } + + // Process added functions. + while (!AddedFuncs.empty()) { + auto *F = AddedFuncs.back(); + AddedFuncs.pop_back(); + auto &FuncStat = getFunctionStat(F); + FunctionStat OldFuncStat; + FunctionStat NewFuncStat(F); + processFuncStatsChanges(F, OldFuncStat, NewFuncStat, Ctx); + NewModStat.addFunctionStat(NewFuncStat); + FuncStat = NewFuncStat; + } + } + + // Then collect some more general statistics, which do not require + // any scanning of SILFunctions or the like. + NewModStat.addMemoryStat(); + NewModStat.addCreatedAndDeletedInstructionsStat(); + + // Process updates. + processModuleStatsChanges(OldModStat, NewModStat, Ctx); + + // Remember the new state of the collected stats. + ModStat = NewModStat; +} + +FunctionStat::FunctionStat(SILFunction *F) : InstCounts(SILInstructionsNum) { + InstCountVisitor V(InstCounts); + V.visitSILFunction(F); + BlockCount = V.getBlockCount(); + InstCount = V.getInstCount(); +} + +} // end anonymous namespace + +/// Updates SILModule stats after finishing executing the +/// transform \p Transform. +/// +/// \param M SILModule to be processed +/// \param Transform the SIL transformation that was just executed +/// \param PM the PassManager being used +void swift::updateSILModuleStatsAfterTransform(SILModule &M, + SILTransform *Transform, + SILPassManager &PM, + int PassNumber, int Duration) { + if (!SILStatsModules && !SILStatsFunctions && !SILStatsDumpAll) + return; + TransformationContext Ctx(M, PM, Transform, PassNumber, Duration); + OptimizerStatsAnalysis *Stats = PM.getAnalysis(); + Stats->updateModuleStats(Ctx); +} + +// This is just a hook for possible extensions in the future. +// It could be used e.g. to detect sequences of consecutive executions +// of the same transform. +void swift::updateSILModuleStatsBeforeTransform(SILModule &M, + SILTransform *Transform, + SILPassManager &PM, + int PassNumber) { + if (!SILStatsModules && !SILStatsFunctions) + return; +} + +SILAnalysis *swift::createOptimizerStatsAnalysis(SILModule *M) { + return new OptimizerStatsAnalysis(M); +} diff --git a/test/SILOptimizer/optimizer_counters.sil b/test/SILOptimizer/optimizer_counters.sil new file mode 100644 index 0000000000000..05bc87229123d --- /dev/null +++ b/test/SILOptimizer/optimizer_counters.sil @@ -0,0 +1,101 @@ +// RUN: %target-sil-opt -assume-parsing-unqualified-ownership-sil -enable-sil-verify-all %s -O -sil-stats-modules 2>&1 | %FileCheck --check-prefix=CHECK-SIL-STATS-MODULES %s +// RUN: %target-sil-opt -assume-parsing-unqualified-ownership-sil -enable-sil-verify-all %s -O -sil-stats-functions 2>&1 | %FileCheck --check-prefix=CHECK-SIL-STATS-FUNCTIONS %s +// RUN: %target-sil-opt -assume-parsing-unqualified-ownership-sil -enable-sil-verify-all %s -O -sil-stats-dump-all 2>&1 | %FileCheck --check-prefix=CHECK-SIL-STATS-ALL %s +// RUN: %target-sil-opt -assume-parsing-unqualified-ownership-sil -enable-sil-verify-all %s -O -sil-stats-modules -sil-stats-only-instructions=integer_literal,builtin 2>&1 | %FileCheck --check-prefix=CHECK-SIL-STATS-ONLY-INSTRUCTIONS %s +// RUN: %target-sil-opt -assume-parsing-unqualified-ownership-sil -enable-sil-verify-all %s -O -sil-stats-functions -sil-stats-only-function=test_simple 2>&1 | %FileCheck --check-prefix=CHECK-SIL-STATS-ONLY-FUNCTION %s +// RUN: %target-sil-opt -assume-parsing-unqualified-ownership-sil -enable-sil-verify-all %s -O -sil-stats-functions -sil-stats-only-functions=test 2>&1 | %FileCheck --check-prefix=CHECK-SIL-STATS-ONLY-FUNCTIONS %s + + +// Test different modes of optimizer counters statistics collection. + +sil_stage canonical + +import Builtin +import Swift + +sil @fatalError : $@convention(thin) () -> Never + +// Check that module level statistics are produced. +// +// CHECK-SIL-STATS-MODULES: module, inst, HighLevel+EarlyLoopOpt, PerformanceConstantPropagation, {{.*}}, 15, 12 +// CHECK-SIL-STATS-MODULES: module, block, HighLevel+EarlyLoopOpt, SimplifyCFG, {{.*}}, 6, 3 +// CHECK-SIL-STATS-MODULES: module, inst, HighLevel+EarlyLoopOpt, SimplifyCFG, {{.*}}, 12, 6 + +// Check that module level statistics are produced. +// +// CHECK-SIL-STATS-FUNCTIONS: function_history, block,{{.*}}, test_multiply +// CHECK-SIL-STATS-FUNCTIONS: function_history, inst,{{.*}}, test_multiply +// CHECK-SIL-STATS-FUNCTIONS: function_history, block,{{.*}}, test_simple +// CHECK-SIL-STATS-FUNCTIONS: function_history, inst,{{.*}}, test_simple +// CHECK-SIL-STATS-FUNCTIONS: function_history, block,{{.*}}, another_simple_func +// CHECK-SIL-STATS-FUNCTIONS: function_history, inst,{{.*}}, another_simple_func + + + +// Check that -sil-stats-all produces module and function level statistics. +// +// CHECK-SIL-STATS-ALL: module, block, +// CHECK-SIL-STATS-ALL: function, inst + +// Check that -sil-stats-only-instructions=integer_literal,builtin produces stats about these instruction. +// +// CHECK-SIL-STATS-ONLY-INSTRUCTIONS: module, inst_integer_literal +// CHECK-SIL-STATS-ONLY-INSTRUCTIONS: module, inst_builtin + +sil @test_multiply : $@convention(thin) () -> Builtin.Int64 { +bb0: + %1 = integer_literal $Builtin.Int64, 10 + %2 = integer_literal $Builtin.Int1, 0 + %3 = builtin "umul_with_overflow_Int64"(%1 : $Builtin.Int64, %1 : $Builtin.Int64, %2 : $Builtin.Int1) : $(Builtin.Int64, Builtin.Int1) + %4 = tuple_extract %3 : $(Builtin.Int64, Builtin.Int1), 1 + cond_br %4, bb1, bb2 + +bb1: + %f = function_ref @fatalError : $@convention(thin) () -> Never + apply %f() : $@convention(thin) () -> Never + unreachable + +bb2: + %v = tuple_extract %3 : $(Builtin.Int64, Builtin.Int1), 0 + br bb3 (%v : $Builtin.Int64) + +bb3(%r : $Builtin.Int64): + return %r: $Builtin.Int64 +} + +// Check that -sil-stats-only-function=test_simple produces stats only about test_simple +// +// CHECK-SIL-STATS-ONLY-FUNCTION-NOT: function_history, block,{{.*}}, test_multiply +// CHECK-SIL-STATS-ONLY-FUNCTION-NOT: function_history, inst,{{.*}}, test_multiply +// CHECK-SIL-STATS-ONLY-FUNCTION-NOT: function_history, block,{{.*}}, another_simple_func +// CHECK-SIL-STATS-ONLY-FUNCTION-NOT: function_history, inst,{{.*}}, another_simple_func +// CHECK-SIL-STATS-ONLY-FUNCTION: function_history, block,{{.*}}, test_simple +// CHECK-SIL-STATS-ONLY-FUNCTION: function_history, inst,{{.*}}, test_simple +// CHECK-SIL-STATS-ONLY-FUNCTION-NOT: function_history, block,{{.*}}, test_multiply +// CHECK-SIL-STATS-ONLY-FUNCTION-NOT: function_history, inst,{{.*}}, test_multiply +// CHECK-SIL-STATS-ONLY-FUNCTION-NOT: function_history, block,{{.*}}, another_simple_func +// CHECK-SIL-STATS-ONLY-FUNCTION-NOT: function_history, inst,{{.*}}, another_simple_func + +sil @test_simple : $@convention(thin) () -> Builtin.Int64 { + %0 = integer_literal $Builtin.Int64, 10 + return %0 : $Builtin.Int64 +} + +sil @another_simple_func : $@convention(thin) () -> Builtin.Int64 { + %0 = integer_literal $Builtin.Int64, 10 + return %0 : $Builtin.Int64 +} + +// Check that -sil-stats-only-functions=test produces stats only about functions, +// whose name contains "test" +// +// CHECK-SIL-STATS-ONLY-FUNCTIONS-NOT: function_history, block,{{.*}}, another_simple_func +// CHECK-SIL-STATS-ONLY-FUNCTIONS-NOT: function_history, inst,{{.*}}, another_simple_func +// CHECK-SIL-STATS-ONLY-FUNCTIONS: function_history, block,{{.*}}, test_multiply +// CHECK-SIL-STATS-ONLY-FUNCTIONS: function_history, inst,{{.*}}, test_multiply +// CHECK-SIL-STATS-ONLY-FUNCTIONS: function_history, block,{{.*}}, test_simple +// CHECK-SIL-STATS-ONLY-FUNCTIONS: function_history, inst,{{.*}}, test_simple +// CHECK-SIL-STATS-ONLY-FUNCTIONS-NOT: function_history, block,{{.*}}, another_simple_func +// CHECK-SIL-STATS-ONLY-FUNCTIONS-NOT: function_history, inst,{{.*}}, another_simple_func + + diff --git a/utils/optimizer_counters_to_sql.py b/utils/optimizer_counters_to_sql.py new file mode 100755 index 0000000000000..03bf3de15dfb4 --- /dev/null +++ b/utils/optimizer_counters_to_sql.py @@ -0,0 +1,143 @@ +#!/usr/bin/env python +# optimizer_counters_to_sql.py - Store CSV counters into SQLite -*- python -*- +# +# This source file is part of the Swift.org open source project +# +# Copyright (c) 2014 - 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 + +import sqlite3 as lite +import sys + + +# A simple class to connect to a DB and store the statistics from a CSV +# (comma separated values) file with optimizer counters there. +# +# See OptimizerCountersAnalysis.md for more details about working with +# produced SQLite database and analyzing the collected optimizer counters. +class OptStatsDB(object): + def __init__(self, dbname): + try: + # Establish a connection to a DB. + con = lite.connect(dbname) + self.con = con + cur = con.cursor() + self.cur = cur + # FIXME: A more efficient representation could be used. + # There could be separate tables for all possible Stage names, + # Transform names, Kind names, Counter names, Symbol names. + # They would get unique integer IDs in their respective tables. + # The Counters table would then use those unique integer IDs + # as foreign keys. + # This way the storage required for Counters may get much + # smaller as it would only store integers instead of long repeating + # strings. + # The drawback of such an approach is that the queries may become + # much more complex to write, as they would need to span over + # multiple tables. + + # Create the required tables, indices, etc. + cur.execute("CREATE TABLE IF NOT EXISTS Counters" + "(Id INTEGER PRIMARY KEY AUTOINCREMENT, " + "Stage TEXT NOT NULL, " + "Transform TEXT NOT NULL, " + "Kind TEXT, " + "Counter TEXT NOT NULL, " + "PassNum INT NOT NULL, " + "Delta NUMBER," + "Old INT, " + "New INT, " + "Duration INT, " + "Symbol TEXT NOT NULL DEFAULT '')") + cur.execute('CREATE INDEX IF NOT EXISTS StageIndex ' + 'ON Counters(Stage)') + cur.execute('CREATE INDEX IF NOT EXISTS TransformIndex ' + 'ON Counters(Transform)') + cur.execute('CREATE INDEX IF NOT EXISTS KindIndex ' + 'ON Counters(Kind)') + cur.execute('CREATE INDEX IF NOT EXISTS CounterIndex ' + 'ON Counters(Counter)') + cur.execute('CREATE INDEX IF NOT EXISTS SymbolIndex ' + 'ON Counters(Symbol)') + except lite.Error as e: + print('Error {}' .format(e.args[0])) + sys.exit(1) + finally: + pass + + def finish(self): + try: + self.con.commit() + self.con.close() + finally: + pass + + # Store a single statistics record into a DB. + def addRecord(self, stage, transform, kind, + counter, passnum, delta, old, new, duration, symbol): + values = [(stage, transform, kind, counter, passnum, + delta, old, new, duration, symbol,), ] + self.cur.executemany( + 'INSERT INTO Counters VALUES ' + '(NULL, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)', + values) + + +# Read input file line by line, parse the lines and store the stats into +# the DB. +def addStatsFromInput(inputFile, db): + for line in inputFile: + # Read next line + # Split into segments + segments = line.split(",") + if len(segments) < 6 or not (segments[0] in [ + 'module', 'function', 'function_history']): + continue + # Trim all values + segments = map(str.strip, segments) + if segments[0] == 'function_history': + # Process history records + delta = 0.0 + (kind, counter, stage, transform, passnum, + old, duration, symbol) = segments + new = old + else: + # Process stats records + (kind, counter, stage, transform, passnum, delta, + old, new, duration, symbol) = segments + + db.addRecord( + stage, + transform, + kind, + counter, + passnum, + delta, + old, + new, + duration, + symbol) + + +def processStatsFile(filename, dbname): + print( + "Copying stats from the file '{}' into database '{}'".format( + filename, + dbname)) + db = OptStatsDB(dbname) + with open(filename, "rb") as inputFile: + addStatsFromInput(inputFile, db) + db.finish() + + +def main(): + filename = sys.argv[1] + dbname = sys.argv[2] + processStatsFile(filename, dbname) + + +if __name__ == '__main__': + main()