Merge pull request #16558 from azat/query_thread_log_current_database

Add current_database into query_thread_log

src/Common/ThreadStatus.h

@@ -172,7 +172,7 @@ protected:
 
     void finalizeQueryProfiler();
 
-    void logToQueryThreadLog(QueryThreadLog & thread_log);
+    void logToQueryThreadLog(QueryThreadLog & thread_log, const String & current_database);
 
     void assertState(const std::initializer_list<int> & permitted_states, const char * description = nullptr) const;
 

src/Interpreters/QueryThreadLog.cpp

@@ -38,6 +38,7 @@ Block QueryThreadLogElement::createBlock()
         {std::make_shared<DataTypeString>(),        "thread_name"},
         {std::make_shared<DataTypeUInt64>(),        "thread_id"},
         {std::make_shared<DataTypeUInt64>(),        "master_thread_id"},
+        {std::make_shared<DataTypeString>(),        "current_database"},
         {std::make_shared<DataTypeString>(),        "query"},
 
         {std::make_shared<DataTypeUInt8>(),         "is_initial_query"},
@@ -91,6 +92,7 @@ void QueryThreadLogElement::appendToBlock(MutableColumns & columns) const
     columns[i++]->insert(thread_id);
     columns[i++]->insert(master_thread_id);
 
+    columns[i++]->insertData(current_database.data(), current_database.size());
     columns[i++]->insertData(query.data(), query.size());
 
     QueryLogElement::appendClientInfo(client_info, columns, i);

src/Interpreters/QueryThreadLog.h

@@ -39,7 +39,9 @@ struct QueryThreadLogElement
     UInt64 thread_id{};
     UInt64 master_thread_id{};
 
+    String current_database;
     String query;
+
     ClientInfo client_info;
 
     std::shared_ptr<ProfileEvents::Counters> profile_counters;

src/Interpreters/ThreadStatusExt.cpp

@@ -243,7 +243,7 @@ void ThreadStatus::finalizePerformanceCounters()
             const auto & settings = query_context->getSettingsRef();
             if (settings.log_queries && settings.log_query_threads)
                 if (auto thread_log = global_context->getQueryThreadLog())
-                    logToQueryThreadLog(*thread_log);
+                    logToQueryThreadLog(*thread_log, query_context->getCurrentDatabase());
         }
     }
     catch (...)
@@ -322,7 +322,7 @@ void ThreadStatus::detachQuery(bool exit_if_already_detached, bool thread_exits)
 #endif
 }
 
-void ThreadStatus::logToQueryThreadLog(QueryThreadLog & thread_log)
+void ThreadStatus::logToQueryThreadLog(QueryThreadLog & thread_log, const String & current_database)
 {
     QueryThreadLogElement elem;
 
@@ -350,6 +350,7 @@ void ThreadStatus::logToQueryThreadLog(QueryThreadLog & thread_log)
     elem.thread_name = getThreadName();
     elem.thread_id = thread_id;
 
+    elem.current_database = current_database;
     if (thread_group)
     {
         {

tests/queries/0_stateless/01547_query_log_current_database.reference

@@ -0,0 +1,2 @@
+1
+1

tests/queries/0_stateless/01547_query_log_current_database.sql

@@ -0,0 +1,37 @@
+--
+-- This is more cleaner approach for writing a test that relies on system.query_log/query_thread_log.
+--
+-- It uses current database, and since clickhouse-test will generate random for
+-- each run you can run the test multiple times without worrying about
+-- overlaps.
+--
+-- There is still event_date/event_time filter for better performance
+-- (even though this is not relevant for runs on CI)
+--
+
+set log_query_threads=1;
+set log_queries_min_type='QUERY_FINISH';
+set log_queries=1;
+select '01547_query_log_current_database' from system.one format Null;
+set log_queries=0;
+set log_query_threads=0;
+
+system flush logs;
+
+select count()
+from system.query_log
+where
+    query like '%01547_query_log_current_database%'
+    and current_database = currentDatabase()
+    and event_date = today()
+    and event_time >= now() - interval 1 minute;
+
+-- at least two threads for processing
+-- (but one just waits for another, sigh)
+select count() == 2
+from system.query_thread_log
+where
+    query like '%01547_query_log_current_database%'
+    and current_database = currentDatabase()
+    and event_date = today()
+    and event_time >= now() - interval 1 minute;

tests/queries/0_stateless/arcadia_skip_list.txt

@@ -155,3 +155,4 @@
 01509_dictionary_preallocate
 01526_max_untracked_memory
 01530_drop_database_atomic_sync
+01547_query_log_current_database