add time print in transform

Kyligence · Apr 12, 2022 · 401d6ec · 401d6ec
1 parent 97c4bc2
commit 401d6ec
Show file tree

Hide file tree

Showing 4 changed files with 22 additions and 2 deletions.
diff --git a/src/Processors/ISimpleTransform.cpp b/src/Processors/ISimpleTransform.cpp
@@ -1,5 +1,6 @@
 #include <Processors/ISimpleTransform.h>
-
+#include <Common/Stopwatch.h>
+#include <common/logger_useful.h>
 
 namespace DB
 {
@@ -52,6 +53,9 @@ ISimpleTransform::Status ISimpleTransform::prepare()
     {
         if (input.isFinished())
         {
+            LOG_DEBUG(&Poco::Logger::get(getName()),
+                      "Processor {} used {} ms\n",
+                      getName(), time/ 1000000UL);
             output.finish();
             return Status::Finished;
         }
@@ -86,7 +90,11 @@ void ISimpleTransform::work()
 
     try
     {
+        Stopwatch watch;
+        watch.start();
         transform(input_data.chunk, output_data.chunk);
+        time += watch.elapsedNanoseconds();
+        watch.stop();
     }
     catch (DB::Exception &)
     {

diff --git a/src/Processors/ISimpleTransform.h b/src/Processors/ISimpleTransform.h
@@ -26,6 +26,7 @@ class ISimpleTransform : public IProcessor
     bool has_output = false;
     bool no_more_data_needed = false;
     const bool skip_empty_chunks;
+    UInt64 time = 0;
 
     /// Set input port NotNeeded after chunk was pulled.
     /// Input port will become needed again only after data was transformed.

diff --git a/src/Processors/ISource.cpp b/src/Processors/ISource.cpp
@@ -1,5 +1,6 @@
 #include <Processors/ISource.h>
-
+#include <Common/Stopwatch.h>
+#include <common/logger_useful.h>
 
 namespace DB
 {
@@ -50,14 +51,23 @@ void ISource::work()
 {
     try
     {
+        Stopwatch watch;
+        watch.start();
         if (auto chunk = tryGenerate())
         {
             current_chunk.chunk = std::move(*chunk);
             if (current_chunk.chunk)
                 has_input = true;
+            time += watch.elapsedNanoseconds();
         }
         else
+        {
             finished = true;
+            LOG_DEBUG(&Poco::Logger::get(getName()),
+                      "Processor {} used {} ms\n",
+                      getName(), time/ 1000000UL);
+        }
+
 
         if (isCancelled())
             finished = true;

diff --git a/src/Processors/ISource.h b/src/Processors/ISource.h
@@ -14,6 +14,7 @@ class ISource : public IProcessor
     bool finished = false;
     bool got_exception = false;
     Port::Data current_chunk;
+    UInt64 time = 0;
 
     virtual Chunk generate();
     virtual std::optional<Chunk> tryGenerate();