diff --git a/mlir/docs/PassManagement.md b/mlir/docs/PassManagement.md index c9d705f0506a..e9ecb99462b8 100644 --- a/mlir/docs/PassManagement.md +++ b/mlir/docs/PassManagement.md @@ -1124,17 +1124,44 @@ pipeline. This display mode is available in mlir-opt via $ mlir-opt foo.mlir -mlir-disable-threading -pass-pipeline='builtin.module(func.func(cse,canonicalize),convert-func-to-llvm)' -mlir-timing -mlir-timing-display=list ===-------------------------------------------------------------------------=== - ... Pass execution timing report ... + ... Execution time report ... ===-------------------------------------------------------------------------=== - Total Execution Time: 0.0203 seconds + Total Execution Time: 0.0135 seconds - ---Wall Time--- --- Name --- - 0.0047 ( 55.9%) Canonicalizer - 0.0019 ( 22.2%) VerifierPass - 0.0016 ( 18.5%) LLVMLoweringPass - 0.0003 ( 3.4%) CSE - 0.0002 ( 1.9%) (A) DominanceInfo - 0.0084 (100.0%) Total + ----Wall Time---- ----Name---- + 0.0135 (100.0%) root + 0.0041 ( 30.1%) Parser + 0.0018 ( 13.3%) ConvertFuncToLLVMPass + 0.0011 ( 8.2%) Output + 0.0007 ( 5.2%) Pipeline Collection : ['func.func'] + 0.0006 ( 4.6%) 'func.func' Pipeline + 0.0005 ( 3.5%) Canonicalizer + 0.0001 ( 0.9%) CSE + 0.0001 ( 0.5%) (A) DataLayoutAnalysis + 0.0000 ( 0.1%) (A) DominanceInfo + 0.0058 ( 43.2%) Rest + 0.0135 (100.0%) Total +``` + +The results can be displayed in JSON format via `-mlir-output-format=json`. + +```shell +$ mlir-opt foo.mlir -mlir-disable-threading -pass-pipeline='builtin.module(func.func(cse,canonicalize),convert-func-to-llvm)' -mlir-timing -mlir-timing-display=list -mlir-output-format=json + +[ +{"wall": {"duration": 0.0135, "percentage": 100.0}, "name": "root"}, +{"wall": {"duration": 0.0041, "percentage": 30.1}, "name": "Parser"}, +{"wall": {"duration": 0.0018, "percentage": 13.3}, "name": "ConvertFuncToLLVMPass"}, +{"wall": {"duration": 0.0011, "percentage": 8.2}, "name": "Output"}, +{"wall": {"duration": 0.0007, "percentage": 5.2}, "name": "Pipeline Collection : ['func.func']"}, +{"wall": {"duration": 0.0006, "percentage": 4.6}, "name": "'func.func' Pipeline"}, +{"wall": {"duration": 0.0005, "percentage": 3.5}, "name": "Canonicalizer"}, +{"wall": {"duration": 0.0001, "percentage": 0.9}, "name": "CSE"}, +{"wall": {"duration": 0.0001, "percentage": 0.5}, "name": "(A) DataLayoutAnalysis"}, +{"wall": {"duration": 0.0000, "percentage": 0.1}, "name": "(A) DominanceInfo"}, +{"wall": {"duration": 0.0058, "percentage": 43.2}, "name": "Rest"}, +{"wall": {"duration": 0.0135, "percentage": 100.0}, "name": "Total"} +] ``` ##### Tree Display Mode @@ -1149,21 +1176,48 @@ invalidated and recomputed. This is the default display mode. $ mlir-opt foo.mlir -mlir-disable-threading -pass-pipeline='builtin.module(func.func(cse,canonicalize),convert-func-to-llvm)' -mlir-timing ===-------------------------------------------------------------------------=== - ... Pass execution timing report ... + ... Execution time report ... ===-------------------------------------------------------------------------=== - Total Execution Time: 0.0249 seconds + Total Execution Time: 0.0127 seconds - ---Wall Time--- --- Name --- - 0.0058 ( 70.8%) 'func.func' Pipeline - 0.0004 ( 4.3%) CSE - 0.0002 ( 2.6%) (A) DominanceInfo - 0.0004 ( 4.8%) VerifierPass - 0.0046 ( 55.4%) Canonicalizer - 0.0005 ( 6.2%) VerifierPass - 0.0005 ( 5.8%) VerifierPass - 0.0014 ( 17.2%) LLVMLoweringPass - 0.0005 ( 6.2%) VerifierPass - 0.0082 (100.0%) Total + ----Wall Time---- ----Name---- + 0.0038 ( 30.2%) Parser + 0.0006 ( 4.8%) 'func.func' Pipeline + 0.0001 ( 0.9%) CSE + 0.0000 ( 0.1%) (A) DominanceInfo + 0.0005 ( 3.7%) Canonicalizer + 0.0017 ( 13.7%) ConvertFuncToLLVMPass + 0.0001 ( 0.6%) (A) DataLayoutAnalysis + 0.0010 ( 8.2%) Output + 0.0054 ( 42.5%) Rest + 0.0127 (100.0%) Total +``` + +The results can be displayed in JSON format via `-mlir-output-format=json`. + +```shell +$ mlir-opt foo.mlir -mlir-disable-threading -pass-pipeline='builtin.module(func.func(cse,canonicalize),convert-func-to-llvm)' -mlir-timing -mlir-output-format=json + +[ +{"wall": {"duration": 0.0038, "percentage": 30.2}, "name": "Parser", "passes": [ +{}]}, +{"wall": {"duration": 0.0006, "percentage": 4.8}, "name": "'func.func' Pipeline", "passes": [ + {"wall": {"duration": 0.0001, "percentage": 0.9}, "name": "CSE", "passes": [ + {"wall": {"duration": 0.0000, "percentage": 0.1}, "name": "(A) DominanceInfo", "passes": [ + {}]}, + {}]}, + {"wall": {"duration": 0.0005, "percentage": 3.7}, "name": "Canonicalizer", "passes": [ + {}]}, +{}]}, +{"wall": {"duration": 0.0017, "percentage": 13.7}, "name": "ConvertFuncToLLVMPass", "passes": [ + {"wall": {"duration": 0.0001, "percentage": 0.6}, "name": "(A) DataLayoutAnalysis", "passes": [ + {}]}, +{}]}, +{"wall": {"duration": 0.0010, "percentage": 8.2}, "name": "Output", "passes": [ +{}]}, +{"wall": {"duration": 0.0054, "percentage": 42.5}, "name": "Rest"}, +{"wall": {"duration": 0.0127, "percentage": 100.0}, "name": "Total"} +] ``` ##### Multi-threaded Pass Timing diff --git a/mlir/include/mlir/Support/Timing.h b/mlir/include/mlir/Support/Timing.h index bc3a642ba322..a8a4bfd1c6cf 100644 --- a/mlir/include/mlir/Support/Timing.h +++ b/mlir/include/mlir/Support/Timing.h @@ -320,6 +320,53 @@ private: Timer timer; }; +//===----------------------------------------------------------------------===// +// OutputStrategy +//===----------------------------------------------------------------------===// + +/// Simple record class to record timing information. +struct TimeRecord { + TimeRecord(double wall = 0.0, double user = 0.0) : wall(wall), user(user) {} + + TimeRecord &operator+=(const TimeRecord &other) { + wall += other.wall; + user += other.user; + return *this; + } + + TimeRecord &operator-=(const TimeRecord &other) { + wall -= other.wall; + user -= other.user; + return *this; + } + + double wall, user; +}; + +/// Facilities for printing timing reports to various output formats. +/// +/// This is an abstract class that serves as the foundation for printing. +/// Users can implement additional output formats by extending this abstract +/// class. +class OutputStrategy { +public: + OutputStrategy(raw_ostream &os) : os(os) {} + virtual ~OutputStrategy() = default; + + virtual void printHeader(const TimeRecord &total) = 0; + virtual void printFooter() = 0; + virtual void printTime(const TimeRecord &time, const TimeRecord &total) = 0; + virtual void printListEntry(StringRef name, const TimeRecord &time, + const TimeRecord &total, + bool lastEntry = false) = 0; + virtual void printTreeEntry(unsigned indent, StringRef name, + const TimeRecord &time, + const TimeRecord &total) = 0; + virtual void printTreeEntryEnd(unsigned indent, bool lastEntry = false) = 0; + + raw_ostream &os; +}; + //===----------------------------------------------------------------------===// // DefaultTimingManager //===----------------------------------------------------------------------===// @@ -351,6 +398,15 @@ public: Tree, }; + /// The different output formats for printing the timers. + enum class OutputFormat { + /// In this format the results are displayed in text format. + Text, + + /// In this format the results are displayed in JSON format. + Json, + }; + DefaultTimingManager(); DefaultTimingManager(DefaultTimingManager &&rhs); ~DefaultTimingManager() override; @@ -372,10 +428,7 @@ public: DisplayMode getDisplayMode() const; /// Change the stream where the output will be printed to. - void setOutput(raw_ostream &os); - - /// Return the current output stream where the output will be printed to. - raw_ostream &getOutput() const; + void setOutput(std::unique_ptr output); /// Print and clear the timing results. Only call this when there are no more /// references to nested timers around, as printing post-processes and clears @@ -408,6 +461,7 @@ protected: private: const std::unique_ptr impl; + std::unique_ptr out; }; /// Register a set of useful command-line options that can be used to configure diff --git a/mlir/lib/Support/Timing.cpp b/mlir/lib/Support/Timing.cpp index 2249312c8e7c..1d6796e9d8dc 100644 --- a/mlir/lib/Support/Timing.cpp +++ b/mlir/lib/Support/Timing.cpp @@ -32,6 +32,7 @@ using namespace mlir; using namespace detail; using DisplayMode = DefaultTimingManager::DisplayMode; +using OutputFormat = DefaultTimingManager::OutputFormat; constexpr llvm::StringLiteral kTimingDescription = "... Execution time report ..."; @@ -109,57 +110,106 @@ TimingIdentifier TimingIdentifier::get(StringRef str, TimingManager &tm) { namespace { -/// Simple record class to record timing information. -struct TimeRecord { - TimeRecord(double wall = 0.0, double user = 0.0) : wall(wall), user(user) {} +class OutputTextStrategy : public OutputStrategy { +public: + OutputTextStrategy(raw_ostream &os) : OutputStrategy(os) {} - TimeRecord &operator+=(const TimeRecord &other) { - wall += other.wall; - user += other.user; - return *this; - } + void printHeader(const TimeRecord &total) override { + // Figure out how many spaces to description name. + unsigned padding = (80 - kTimingDescription.size()) / 2; + os << "===" << std::string(73, '-') << "===\n"; + os.indent(padding) << kTimingDescription << '\n'; + os << "===" << std::string(73, '-') << "===\n"; - TimeRecord &operator-=(const TimeRecord &other) { - wall -= other.wall; - user -= other.user; - return *this; - } - - /// Print the current time record to 'os', with a breakdown showing - /// contributions to the give 'total' time record. - void print(raw_ostream &os, const TimeRecord &total) { + // Print the total time followed by the section headers. + os << llvm::format(" Total Execution Time: %.4f seconds\n\n", total.wall); if (total.user != total.wall) - os << llvm::format(" %8.4f (%5.1f%%)", user, 100.0 * user / total.user); - os << llvm::format(" %8.4f (%5.1f%%) ", wall, 100.0 * wall / total.wall); + os << " ----User Time----"; + os << " ----Wall Time---- ----Name----\n"; } - double wall, user; + void printFooter() override { os.flush(); } + + void printTime(const TimeRecord &time, const TimeRecord &total) override { + if (total.user != total.wall) { + os << llvm::format(" %8.4f (%5.1f%%)", time.user, + 100.0 * time.user / total.user); + } + os << llvm::format(" %8.4f (%5.1f%%) ", time.wall, + 100.0 * time.wall / total.wall); + } + + void printListEntry(StringRef name, const TimeRecord &time, + const TimeRecord &total, bool lastEntry) override { + printTime(time, total); + os << name << "\n"; + } + + void printTreeEntry(unsigned indent, StringRef name, const TimeRecord &time, + const TimeRecord &total) override { + printTime(time, total); + os.indent(indent) << name << "\n"; + } + + void printTreeEntryEnd(unsigned indent, bool lastEntry) override {} +}; + +class OutputJsonStrategy : public OutputStrategy { +public: + OutputJsonStrategy(raw_ostream &os) : OutputStrategy(os) {} + + void printHeader(const TimeRecord &total) override { os << "[" << "\n"; } + + void printFooter() override { + os << "]" << "\n"; + os.flush(); + } + + void printTime(const TimeRecord &time, const TimeRecord &total) override { + if (total.user != total.wall) { + os << "\"user\": {"; + os << "\"duration\": " << llvm::format("%8.4f", time.user) << ", "; + os << "\"percentage\": " + << llvm::format("%5.1f", 100.0 * time.user / total.user); + os << "}, "; + } + os << "\"wall\": {"; + os << "\"duration\": " << llvm::format("%8.4f", time.wall) << ", "; + os << "\"percentage\": " + << llvm::format("%5.1f", 100.0 * time.wall / total.wall); + os << "}"; + } + + void printListEntry(StringRef name, const TimeRecord &time, + const TimeRecord &total, bool lastEntry) override { + os << "{"; + printTime(time, total); + os << ", \"name\": " << "\"" << name << "\""; + os << "}"; + if (!lastEntry) + os << ","; + os << "\n"; + } + + void printTreeEntry(unsigned indent, StringRef name, const TimeRecord &time, + const TimeRecord &total) override { + os.indent(indent) << "{"; + printTime(time, total); + os << ", \"name\": " << "\"" << name << "\""; + os << ", \"passes\": [" << "\n"; + } + + void printTreeEntryEnd(unsigned indent, bool lastEntry) override { + os.indent(indent) << "{}]"; + os << "}"; + if (!lastEntry) + os << ","; + os << "\n"; + } }; } // namespace -/// Utility to print a single line entry in the timer output. -static void printTimeEntry(raw_ostream &os, unsigned indent, StringRef name, - TimeRecord time, TimeRecord total) { - time.print(os, total); - os.indent(indent) << name << "\n"; -} - -/// Utility to print the timer heading information. -static void printTimeHeader(raw_ostream &os, TimeRecord total) { - // Figure out how many spaces to description name. - unsigned padding = (80 - kTimingDescription.size()) / 2; - os << "===" << std::string(73, '-') << "===\n"; - os.indent(padding) << kTimingDescription << '\n'; - os << "===" << std::string(73, '-') << "===\n"; - - // Print the total time followed by the section headers. - os << llvm::format(" Total Execution Time: %.4f seconds\n\n", total.wall); - if (total.user != total.wall) - os << " ----User Time----"; - os << " ----Wall Time---- ----Name----\n"; -} - //===----------------------------------------------------------------------===// // Timer Implementation for DefaultTimingManager //===----------------------------------------------------------------------===// @@ -176,7 +226,8 @@ public: using ChildrenMap = llvm::MapVector>; using AsyncChildrenMap = llvm::DenseMap; - TimerImpl(std::string &&name) : threadId(llvm::get_threadid()), name(name) {} + TimerImpl(std::string &&name, std::unique_ptr &output) + : threadId(llvm::get_threadid()), name(name), output(output) {} /// Start the timer. void start() { startTime = std::chrono::steady_clock::now(); } @@ -206,7 +257,7 @@ public: TimerImpl *nestTail(std::unique_ptr &child, function_ref nameBuilder) { if (!child) - child = std::make_unique(nameBuilder()); + child = std::make_unique(nameBuilder(), output); return child.get(); } @@ -320,7 +371,7 @@ public: } /// Print the timing result in list mode. - void printAsList(raw_ostream &os, TimeRecord total) { + void printAsList(TimeRecord total) { // Flatten the leaf timers in the tree and merge them by name. llvm::StringMap mergedTimers; std::function addTimer = [&](TimerImpl *timer) { @@ -343,34 +394,37 @@ public: // Print the timing information sequentially. for (auto &timeData : timerNameAndTime) - printTimeEntry(os, 0, timeData.first, timeData.second, total); + output->printListEntry(timeData.first, timeData.second, total); } /// Print the timing result in tree mode. - void printAsTree(raw_ostream &os, TimeRecord total, unsigned indent = 0) { + void printAsTree(TimeRecord total, unsigned indent = 0) { unsigned childIndent = indent; if (!hidden) { - printTimeEntry(os, indent, name, getTimeRecord(), total); + output->printTreeEntry(indent, name, getTimeRecord(), total); childIndent += 2; } for (auto &child : children) { - child.second->printAsTree(os, total, childIndent); + child.second->printAsTree(total, childIndent); + } + if (!hidden) { + output->printTreeEntryEnd(indent); } } /// Print the current timing information. - void print(raw_ostream &os, DisplayMode displayMode) { + void print(DisplayMode displayMode) { // Print the banner. auto total = getTimeRecord(); - printTimeHeader(os, total); + output->printHeader(total); // Defer to a specialized printer for each display mode. switch (displayMode) { case DisplayMode::List: - printAsList(os, total); + printAsList(total); break; case DisplayMode::Tree: - printAsTree(os, total); + printAsTree(total); break; } @@ -379,9 +433,9 @@ public: auto rest = total; for (auto &child : children) rest -= child.second->getTimeRecord(); - printTimeEntry(os, 0, "Rest", rest, total); - printTimeEntry(os, 0, "Total", total, total); - os.flush(); + output->printListEntry("Rest", rest, total); + output->printListEntry("Total", total, total, /*lastEntry=*/true); + output->printFooter(); } /// The last time instant at which the timer was started. @@ -415,6 +469,8 @@ public: /// Mutex for the async children. std::mutex asyncMutex; + + std::unique_ptr &output; }; } // namespace @@ -435,9 +491,6 @@ public: /// The configured display mode. DisplayMode displayMode = DisplayMode::Tree; - /// The stream where we should print our output. This will always be non-null. - raw_ostream *output = &llvm::errs(); - /// The root timer. std::unique_ptr rootTimer; }; @@ -469,26 +522,22 @@ DefaultTimingManager::DisplayMode DefaultTimingManager::getDisplayMode() const { } /// Change the stream where the output will be printed to. -void DefaultTimingManager::setOutput(raw_ostream &os) { impl->output = &os; } - -/// Return the current output stream where the output will be printed to. -raw_ostream &DefaultTimingManager::getOutput() const { - assert(impl->output); - return *impl->output; +void DefaultTimingManager::setOutput(std::unique_ptr output) { + out = std::move(output); } /// Print and clear the timing results. void DefaultTimingManager::print() { if (impl->enabled) { impl->rootTimer->finalize(); - impl->rootTimer->print(*impl->output, impl->displayMode); + impl->rootTimer->print(impl->displayMode); } clear(); } /// Clear the timing results. void DefaultTimingManager::clear() { - impl->rootTimer = std::make_unique("root"); + impl->rootTimer = std::make_unique("root", out); impl->rootTimer->hidden = true; } @@ -500,13 +549,13 @@ void DefaultTimingManager::dumpTimers(raw_ostream &os) { /// Debug print the timers as a list. void DefaultTimingManager::dumpAsList(raw_ostream &os) { impl->rootTimer->finalize(); - impl->rootTimer->print(os, DisplayMode::List); + impl->rootTimer->print(DisplayMode::List); } /// Debug print the timers as a tree. void DefaultTimingManager::dumpAsTree(raw_ostream &os) { impl->rootTimer->finalize(); - impl->rootTimer->print(os, DisplayMode::Tree); + impl->rootTimer->print(DisplayMode::Tree); } std::optional DefaultTimingManager::rootTimer() { @@ -549,6 +598,13 @@ struct DefaultTimingManagerOptions { "display the results in a list sorted by total time"), clEnumValN(DisplayMode::Tree, "tree", "display the results ina with a nested tree view"))}; + llvm::cl::opt outputFormat{ + "mlir-output-format", llvm::cl::desc("Output format for timing data"), + llvm::cl::init(OutputFormat::Text), + llvm::cl::values(clEnumValN(OutputFormat::Text, "text", + "display the results in text format"), + clEnumValN(OutputFormat::Json, "json", + "display the results in JSON format"))}; }; } // namespace @@ -564,4 +620,11 @@ void mlir::applyDefaultTimingManagerCLOptions(DefaultTimingManager &tm) { return; tm.setEnabled(options->timing); tm.setDisplayMode(options->displayMode); + + std::unique_ptr printer; + if (options->outputFormat == OutputFormat::Text) + printer = std::make_unique(llvm::errs()); + else if (options->outputFormat == OutputFormat::Json) + printer = std::make_unique(llvm::errs()); + tm.setOutput(std::move(printer)); } diff --git a/mlir/test/Pass/pass-timing.mlir b/mlir/test/Pass/pass-timing.mlir index bd5d611b4715..cfb4b74cd19c 100644 --- a/mlir/test/Pass/pass-timing.mlir +++ b/mlir/test/Pass/pass-timing.mlir @@ -1,5 +1,7 @@ // RUN: mlir-opt %s -mlir-disable-threading=true -verify-each=true -pass-pipeline='builtin.module(func.func(cse,canonicalize,cse))' -mlir-timing -mlir-timing-display=list 2>&1 | FileCheck -check-prefix=LIST %s +// RUN: mlir-opt %s -mlir-disable-threading=true -verify-each=true -pass-pipeline='builtin.module(func.func(cse,canonicalize,cse))' -mlir-timing -mlir-timing-display=list -mlir-output-format=json 2>&1 | FileCheck -check-prefix=LIST-JSON %s // RUN: mlir-opt %s -mlir-disable-threading=true -verify-each=true -pass-pipeline='builtin.module(func.func(cse,canonicalize,cse))' -mlir-timing -mlir-timing-display=tree 2>&1 | FileCheck -check-prefix=PIPELINE %s +// RUN: mlir-opt %s -mlir-disable-threading=true -verify-each=true -pass-pipeline='builtin.module(func.func(cse,canonicalize,cse))' -mlir-timing -mlir-timing-display=tree -mlir-output-format=json 2>&1 | FileCheck -check-prefix=PIPELINE-JSON %s // RUN: mlir-opt %s -mlir-disable-threading=false -verify-each=true -pass-pipeline='builtin.module(func.func(cse,canonicalize,cse))' -mlir-timing -mlir-timing-display=list 2>&1 | FileCheck -check-prefix=MT_LIST %s // RUN: mlir-opt %s -mlir-disable-threading=false -verify-each=true -pass-pipeline='builtin.module(func.func(cse,canonicalize,cse))' -mlir-timing -mlir-timing-display=tree 2>&1 | FileCheck -check-prefix=MT_PIPELINE %s // RUN: mlir-opt %s -mlir-disable-threading=true -verify-each=false -test-pm-nested-pipeline -mlir-timing -mlir-timing-display=tree 2>&1 | FileCheck -check-prefix=NESTED_PIPELINE %s @@ -12,6 +14,14 @@ // LIST-DAG: DominanceInfo // LIST: Total +// LIST-JSON-NOT: Execution time report +// LIST-JSON-NOT: Total Execution Time: +// LIST-JSON-NOT: Name +// LIST-JSON-DAG: "name": "Canonicalizer"} +// LIST-JSON-DAG: "name": "CSE"} +// LIST-JSON-DAG: "name": "(A) DominanceInfo"} +// LIST-JSON: "name": "Total"} + // PIPELINE: Execution time report // PIPELINE: Total Execution Time: // PIPELINE: Name @@ -26,6 +36,28 @@ // PIPELINE-NEXT: Rest // PIPELINE-NEXT: Total +// PIPELINE-JSON-NOT: Execution time report +// PIPELINE-JSON-NOT: Total Execution Time: +// PIPELINE-JSON-NOT: Name +// PIPELINE-JSON: "name": "Parser", "passes": [ +// PIPELINE-JSON-NEXT: {}]}, +// PIPELINE-JSON-NEXT: "name": "'func.func' Pipeline", "passes": [ +// PIPELINE-JSON-NEXT: "name": "CSE", "passes": [ +// PIPELINE-JSON-NEXT: "name": "(A) DominanceInfo", "passes": [ +// PIPELINE-JSON-NEXT: {}]}, +// PIPELINE-JSON-NEXT: {}]}, +// PIPELINE-JSON-NEXT: "name": "Canonicalizer", "passes": [ +// PIPELINE-JSON-NEXT: {}]}, +// PIPELINE-JSON-NEXT: "name": "CSE", "passes": [ +// PIPELINE-JSON-NEXT: "name": "(A) DominanceInfo", "passes": [ +// PIPELINE-JSON-NEXT: {}]}, +// PIPELINE-JSON-NEXT: {}]}, +// PIPELINE-JSON-NEXT: {}]}, +// PIPELINE-JSON-NEXT: "name": "Output", "passes": [ +// PIPELINE-JSON-NEXT: {}]}, +// PIPELINE-JSON-NEXT: "name": "Rest" +// PIPELINE-JSON-NEXT: "name": "Total" + // MT_LIST: Execution time report // MT_LIST: Total Execution Time: // MT_LIST: Name