A follow-up for trace log overflow in perftests

The start was in https://github.com/ClickHouse/ClickHouse/pull/11026
It turned out that the problem was due to the incorrect mutate()
implementation that lead to quadratic amount of column copying. This
problem has since been fixed.

Remove the excessively verbose logging, and also change appendToBlock of
LogElement's to accept mutable columns instead of accepting a block and
mutating it on each call. It looks wasteful, even though it is almost a
noop.

src/Interpreters/MetricLog.cpp

@@ -35,10 +35,8 @@ Block MetricLogElement::createBlock()
 }
 
 
-void MetricLogElement::appendToBlock(Block & block) const
+void MetricLogElement::appendToBlock(MutableColumns & columns) const
 {
-    MutableColumns columns = block.mutateColumns();
-
     size_t column_idx = 0;
 
     columns[column_idx++]->insert(DateLUT::instance().toDayNum(event_time));
@@ -50,8 +48,6 @@ void MetricLogElement::appendToBlock(Block & block) const
 
     for (size_t i = 0, end = CurrentMetrics::end(); i < end; ++i)
         columns[column_idx++]->insert(current_metrics[i]);
-
-    block.setColumns(std::move(columns));
 }
 
 

src/Interpreters/MetricLog.h

@@ -25,7 +25,7 @@ struct MetricLogElement
 
     static std::string name() { return "MetricLog"; }
     static Block createBlock();
-    void appendToBlock(Block & block) const;
+    void appendToBlock(MutableColumns & columns) const;
 };
 
 

src/Interpreters/PartLog.cpp

@@ -58,10 +58,8 @@ Block PartLogElement::createBlock()
     };
 }
 
-void PartLogElement::appendToBlock(Block & block) const
+void PartLogElement::appendToBlock(MutableColumns & columns) const
 {
-    MutableColumns columns = block.mutateColumns();
-
     size_t i = 0;
 
     columns[i++]->insert(event_type);
@@ -92,8 +90,6 @@ void PartLogElement::appendToBlock(Block & block) const
 
     columns[i++]->insert(error);
     columns[i++]->insert(exception);
-
-    block.setColumns(std::move(columns));
 }
 
 

src/Interpreters/PartLog.h

@@ -50,7 +50,7 @@ struct PartLogElement
     static std::string name() { return "PartLog"; }
 
     static Block createBlock();
-    void appendToBlock(Block & block) const;
+    void appendToBlock(MutableColumns & columns) const;
 };
 
 class IMergeTreeDataPart;

src/Interpreters/QueryLog.cpp

@@ -85,10 +85,8 @@ Block QueryLogElement::createBlock()
 }
 
 
-void QueryLogElement::appendToBlock(Block & block) const
+void QueryLogElement::appendToBlock(MutableColumns & columns) const
 {
-    MutableColumns columns = block.mutateColumns();
-
     size_t i = 0;
 
     columns[i++]->insert(type);
@@ -146,8 +144,6 @@ void QueryLogElement::appendToBlock(Block & block) const
         columns[i++]->insertDefault();
         columns[i++]->insertDefault();
     }
-
-    block.setColumns(std::move(columns));
 }
 
 void QueryLogElement::appendClientInfo(const ClientInfo & client_info, MutableColumns & columns, size_t & i)

src/Interpreters/QueryLog.h

@@ -62,7 +62,7 @@ struct QueryLogElement
     static std::string name() { return "QueryLog"; }
 
     static Block createBlock();
-    void appendToBlock(Block & block) const;
+    void appendToBlock(MutableColumns & columns) const;
 
     static void appendClientInfo(const ClientInfo & client_info, MutableColumns & columns, size_t & i);
 };

src/Interpreters/QueryThreadLog.cpp

@@ -67,10 +67,8 @@ Block QueryThreadLogElement::createBlock()
     };
 }
 
-void QueryThreadLogElement::appendToBlock(Block & block) const
+void QueryThreadLogElement::appendToBlock(MutableColumns & columns) const
 {
-    MutableColumns columns = block.mutateColumns();
-
     size_t i = 0;
 
     columns[i++]->insert(DateLUT::instance().toDayNum(event_time));
@@ -107,8 +105,6 @@ void QueryThreadLogElement::appendToBlock(Block & block) const
         columns[i++]->insertDefault();
         columns[i++]->insertDefault();
     }
-
-    block.setColumns(std::move(columns));
 }
 
 }

src/Interpreters/QueryThreadLog.h

@@ -43,7 +43,7 @@ struct QueryThreadLogElement
     static std::string name() { return "QueryThreadLog"; }
 
     static Block createBlock();
-    void appendToBlock(Block & block) const;
+    void appendToBlock(MutableColumns & columns) const;
 };
 
 

src/Interpreters/SystemLog.h

@@ -52,7 +52,7 @@ namespace DB
 
         static std::string name();
         static Block createBlock();
-        void appendToBlock(Block & block) const;
+        void appendToBlock(MutableColumns & columns) const;
     };
     */
 
@@ -340,9 +340,8 @@ void SystemLog<LogElement>::savingThreadFunction()
             uint64_t to_flush_end = 0;
 
             {
-                LOG_TRACE(log, "Sleeping");
                 std::unique_lock lock(mutex);
-                const bool predicate = flush_event.wait_for(lock,
+                flush_event.wait_for(lock,
                     std::chrono::milliseconds(flush_interval_milliseconds),
                     [&] ()
                     {
@@ -359,13 +358,6 @@ void SystemLog<LogElement>::savingThreadFunction()
                 queue.swap(to_flush);
 
                 exit_this_thread = is_shutdown;
-
-                LOG_TRACE(log, "Woke up"
-                    << (predicate ? " by condition" : " by timeout ("
-                            + toString(flush_interval_milliseconds) + " ms)")
-                    << ", " << to_flush.size() << " elements to flush"
-                    << " up to " << to_flush_end
-                    << (is_shutdown ? ", shutdown requested" : ""));
             }
 
             if (to_flush.empty())
@@ -399,8 +391,10 @@ void SystemLog<LogElement>::flushImpl(const std::vector<LogElement> & to_flush,
         prepareTable();
 
         Block block = LogElement::createBlock();
+        MutableColumns columns = block.mutateColumns();
         for (const auto & elem : to_flush)
-            elem.appendToBlock(block);
+            elem.appendToBlock(columns);
+        block.setColumns(std::move(columns));
 
         /// We write to table indirectly, using InterpreterInsertQuery.
         /// This is needed to support DEFAULT-columns in table.

src/Interpreters/TextLog.cpp

@@ -46,10 +46,8 @@ Block TextLogElement::createBlock()
     };
 }
 
-void TextLogElement::appendToBlock(Block & block) const
+void TextLogElement::appendToBlock(MutableColumns & columns) const
 {
-    MutableColumns columns = block.mutateColumns();
-
     size_t i = 0;
 
     columns[i++]->insert(DateLUT::instance().toDayNum(event_time));
@@ -68,8 +66,6 @@ void TextLogElement::appendToBlock(Block & block) const
 
     columns[i++]->insert(source_file);
     columns[i++]->insert(source_line);
-
-    block.setColumns(std::move(columns));
 }
 
 TextLog::TextLog(Context & context_, const String & database_name_,

src/Interpreters/TextLog.h

@@ -25,7 +25,7 @@ struct TextLogElement
 
     static std::string name() { return "TextLog"; }
     static Block createBlock();
-    void appendToBlock(Block & block) const;
+    void appendToBlock(MutableColumns & columns) const;
 };
 
 class TextLog : public SystemLog<TextLogElement>

src/Interpreters/TraceLog.cpp

@@ -35,10 +35,8 @@ Block TraceLogElement::createBlock()
     };
 }
 
-void TraceLogElement::appendToBlock(Block & block) const
+void TraceLogElement::appendToBlock(MutableColumns & columns) const
 {
-    MutableColumns columns = block.mutateColumns();
-
     size_t i = 0;
 
     columns[i++]->insert(DateLUT::instance().toDayNum(event_time));
@@ -50,6 +48,4 @@ void TraceLogElement::appendToBlock(Block & block) const
     columns[i++]->insertData(query_id.data(), query_id.size());
     columns[i++]->insert(trace);
     columns[i++]->insert(size);
-
-    block.setColumns(std::move(columns));
 }

src/Interpreters/TraceLog.h

@@ -24,7 +24,7 @@ struct TraceLogElement
 
     static std::string name() { return "TraceLog"; }
     static Block createBlock();
-    void appendToBlock(Block & block) const;
+    void appendToBlock(MutableColumns & columns) const;
 };
 
 class TraceLog : public SystemLog<TraceLogElement>