Refresh table acecss information before the final query_log

Table access should show the tables used by joins in dependent views

src/DataStreams/PushingToViewsBlockOutputStream.cpp

@@ -148,7 +148,7 @@ PushingToViewsBlockOutputStream::PushingToViewsBlockOutputStream(
         views.emplace_back(ViewInfo{std::move(query), database_table, std::move(out), nullptr, std::move(runtime_stats)});
         current_thread = running_thread;
 
-        /// Add the view to the query_log
+        /// Add the view to the query access info so it can appear in system.query_log
         if (!no_destination)
         {
             getContext()->getQueryContext()->addQueryAccessInfo(

src/Interpreters/executeQuery.cpp

@@ -672,7 +672,7 @@ static std::tuple<ASTPtr, BlockIO> executeQueryImpl(
             }
 
             /// Common code for finish and exception callbacks
-            auto status_info_to_query_log = [](QueryLogElement &element, const QueryStatusInfo &info, const ASTPtr query_ast) mutable
+            auto status_info_to_query_log = [](QueryLogElement &element, const QueryStatusInfo &info, const ASTPtr query_ast, ContextMutablePtr context_ptr) mutable
             {
                 DB::UInt64 query_time = info.elapsed_seconds * 1000000;
                 ProfileEvents::increment(ProfileEvents::QueryTimeMicroseconds, query_time);
@@ -697,6 +697,15 @@ static std::tuple<ASTPtr, BlockIO> executeQueryImpl(
 
                 element.thread_ids = std::move(info.thread_ids);
                 element.profile_counters = std::move(info.profile_counters);
+
+                /// We need to refresh the access info since dependent views might have added extra information, either during
+                /// creation of the view (PushingToViewsBlockOutputStream) or while executing its internal SELECT
+                const auto & access_info = context_ptr->getQueryAccessInfo();
+                element.query_databases = access_info.databases;
+                element.query_tables = access_info.tables;
+                element.query_columns = access_info.columns;
+                element.query_projections = access_info.projections;
+                element.query_views = access_info.views;
             };
 
             /// Also make possible for caller to log successful query finish and exception during execution.
@@ -727,7 +736,7 @@ static std::tuple<ASTPtr, BlockIO> executeQueryImpl(
                 const auto finish_time = std::chrono::system_clock::now();
                 elem.event_time = time_in_seconds(finish_time);
                 elem.event_time_microseconds = time_in_microseconds(finish_time);
-                status_info_to_query_log(elem, info, ast);
+                status_info_to_query_log(elem, info, ast, context);
 
                 auto progress_callback = context->getProgressCallback();
 
@@ -850,7 +859,7 @@ static std::tuple<ASTPtr, BlockIO> executeQueryImpl(
                 if (process_list_elem)
                 {
                     QueryStatusInfo info = process_list_elem->getInfo(true, current_settings.log_profile_events, false);
-                    status_info_to_query_log(elem, info, ast);
+                    status_info_to_query_log(elem, info, ast, context);
                 }
 
                 if (current_settings.calculate_text_stack_trace)

tests/queries/0_stateless/01925_query_views_log_current_database.reference

@@ -2,3 +2,5 @@
 {"stage":"Depending views","view_name":"default.matview_a_to_b","view_target":"default.table_b","view_query":"SELECT toFloat64(a) AS a, b AS count FROM default.table_a"}
 {"stage":"Depending views","view_name":"default.matview_b_to_c","view_target":"default.table_c","view_query":"SELECT sum(a) AS a FROM default.table_b"}
 {"stage":"Depending views","view_name":"default.table_b_live_view","view_target":"default.table_b_live_view","view_query":"SELECT sum(a + b) FROM default.table_b"}
+{"stage":"Query log rows 2","read_rows":"50","written_rows":"100","databases":["_table_function","default"],"tables":["_table_function.numbers","default.table_d","default.table_e","default.table_f"],"views":["default.matview_join_d_e"]}
+{"stage":"Depending views 2","view_name":"default.matview_join_d_e","view_target":"default.table_f","view_query":"SELECT table_d.a AS a, table_e.count AS count FROM default.table_d LEFT JOIN default.table_e ON table_d.a = table_e.a"}

tests/queries/0_stateless/01925_query_views_log_current_database.sql

@@ -7,9 +7,16 @@ CREATE TABLE table_a (a String, b Int64) ENGINE = MergeTree ORDER BY b;
 CREATE TABLE table_b (a Float64,  b Int64) ENGINE = MergeTree ORDER BY tuple();
 CREATE TABLE table_c (a Float64) ENGINE = MergeTree ORDER BY a;
 
+CREATE TABLE table_d (a Float64, count Int64) ENGINE MergeTree ORDER BY a;
+CREATE TABLE table_e (a Float64, count Int64) ENGINE MergeTree ORDER BY a;
+CREATE TABLE table_f (a Float64, count Int64) ENGINE MergeTree ORDER BY a;
+
 -- SETUP MATERIALIZED VIEWS
 CREATE MATERIALIZED VIEW matview_a_to_b TO table_b AS SELECT toFloat64(a) AS a, b AS count FROM table_a;
 CREATE MATERIALIZED VIEW matview_b_to_c TO table_c AS SELECT SUM(a) as a FROM table_b;
+
+CREATE MATERIALIZED VIEW matview_join_d_e TO table_f AS SELECT table_d.a as a, table_e.count as count FROM table_d LEFT JOIN table_e ON table_d.a = table_e.a;
+
 -- We don't include test materialized views here since the name is based on the uuid on atomic databases
 -- and that makes the test harder to read
 
@@ -25,8 +32,14 @@ SET log_queries=1;
 
 -- INSERT 1
 INSERT INTO table_a SELECT '111', * FROM numbers(100);
+
+-- INSERT 2
+INSERT INTO table_d SELECT 0.5, * FROM numbers(50);
+
 SYSTEM FLUSH LOGS;
 
+
+-- CHECK LOGS OF INSERT 1
 SELECT
     'Query log rows' as stage,
     read_rows,
@@ -35,10 +48,9 @@ SELECT
     arraySort(tables) as tables,
     arraySort(views) as views
 FROM system.query_log
-WHERE
+WHERE query like '-- INSERT 1%INSERT INTO table_a%'
-    query like '-- INSERT 1%INSERT INTO table_a%'
+  AND current_database = currentDatabase()
-    AND current_database = currentDatabase()
+  AND event_date >= yesterday()
-    AND event_date >= yesterday()
 FORMAT JSONEachRow;
 
 SELECT
@@ -59,9 +71,45 @@ WHERE initial_query_id =
 ORDER BY view_name
 FORMAT JSONEachRow;
 
+-- CHECK LOGS OF INSERT 2
+SELECT
+    'Query log rows 2' as stage,
+    read_rows,
+    written_rows,
+    arraySort(databases) as databases,
+    arraySort(tables) as tables,
+    arraySort(views) as views
+FROM system.query_log
+WHERE query like '-- INSERT 2%INSERT INTO table_d%'
+  AND current_database = currentDatabase()
+  AND event_date >= yesterday()
+FORMAT JSONEachRow;
+
+SELECT
+    'Depending views 2' as stage,
+    view_name,
+    view_target,
+    view_query
+FROM system.query_views_log
+WHERE initial_query_id =
+      (
+          SELECT initial_query_id
+          FROM system.query_log
+          WHERE query like '-- INSERT 2%INSERT INTO table_d%'
+            AND current_database = currentDatabase()
+            AND event_date >= yesterday()
+          LIMIT 1
+      )
+ORDER BY view_name
+    FORMAT JSONEachRow;
+
 -- TEARDOWN
 DROP TABLE table_b_live_view;
 DROP TABLE matview_a_to_b;
 DROP TABLE matview_b_to_c;
+DROP TABLE table_f;
+DROP TABLE table_e;
+DROP TABLE table_d;
+DROP TABLE table_c;
 DROP TABLE table_b;
 DROP TABLE table_a;