Merge pull request #1417 from ivan444/timings

Log how long it took to parse files and extract kythe facts
chipsalliance · Aug 31, 2022 · 537ca0c · 537ca0c
2 parents 86a2682 + c4bb18e
commit 537ca0c
Show file tree

Hide file tree

Showing 4 changed files with 11 additions and 0 deletions.
diff --git a/verilog/analysis/BUILD b/verilog/analysis/BUILD
@@ -346,6 +346,7 @@ cc_library(
         "@com_google_absl//absl/status",
         "@com_google_absl//absl/status:statusor",
         "@com_google_absl//absl/strings",
+        "@com_google_absl//absl/time",
         "@com_google_absl//absl/types:optional",
     ],
 )

diff --git a/verilog/analysis/verilog_project.cc b/verilog/analysis/verilog_project.cc
@@ -25,6 +25,7 @@
 #include "absl/strings/str_cat.h"
 #include "absl/strings/str_join.h"
 #include "absl/strings/strip.h"
+#include "absl/time/time.h"
 #include "absl/types/optional.h"
 #include "common/text/text_structure.h"
 #include "common/util/file_util.h"
@@ -70,7 +71,10 @@ absl::Status VerilogSourceFile::Parse() {
   if (!status_.ok()) return status_;
 
   // Lex, parse, populate underlying TextStructureView.
+  const absl::Time analyze_start = absl::Now();
   status_ = analyzed_structure_->Analyze();
+  LOG(INFO) << "Analyzed " << ResolvedPath() << " in "
+            << absl::ToInt64Milliseconds(absl::Now() - analyze_start) << "ms";
   state_ = State::kParsed;
   return status_;
 }

diff --git a/verilog/tools/kythe/BUILD b/verilog/tools/kythe/BUILD
@@ -99,6 +99,7 @@ cc_library(
         "@com_google_absl//absl/container:node_hash_set",
         "@com_google_absl//absl/memory",
         "@com_google_absl//absl/strings",
+        "@com_google_absl//absl/time",
     ],
 )
 

diff --git a/verilog/tools/kythe/kythe_facts_extractor.cc b/verilog/tools/kythe/kythe_facts_extractor.cc
@@ -28,6 +28,7 @@
 #include "absl/memory/memory.h"
 #include "absl/strings/escaping.h"
 #include "absl/strings/str_cat.h"
+#include "absl/time/time.h"
 #include "common/strings/compare.h"
 #include "common/util/logging.h"
 #include "common/util/tree_operations.h"
@@ -321,6 +322,7 @@ void StreamKytheFactsEntries(KytheOutput* kythe_output,
 
   // Process each file in the original listed order.
   for (const IndexingFactNode& root : file_list.Children()) {
+    const absl::Time extraction_start = absl::Now();
     // 'root' corresponds to the fact tree for a particular file.
     // 'file_path' is path-resolved.
     const absl::string_view file_path(GetFilePathFromRoot(root));
@@ -344,6 +346,9 @@ void StreamKytheFactsEntries(KytheOutput* kythe_output,
     const auto indexing_data = kythe_extractor.ExtractFile(root);
     for (const Fact& fact : indexing_data.facts) kythe_output->Emit(fact);
     for (const Edge& edge : indexing_data.edges) kythe_output->Emit(edge);
+    LOG(INFO) << "Extracted Kythe facts of " << source->ResolvedPath() << " in "
+              << absl::ToInt64Milliseconds(absl::Now() - extraction_start)
+              << "ms";
   }
 
   VLOG(1) << "end of " << __FUNCTION__;