MDEV-30972: ANALYZE FORMAT=JSON: some time is unaccounted-for in BNL-H join

After MDEV-30830 has added block-nl-join.r_unpack_time_ms, it became
apparent that there is some unaccounted-for time in BNL join operation,
namely the time that is spent after unpacking the join buffer record.

Fix this by adding a Gap_time_tracker to track the time that is spent
after unpacking the join buffer record and before any next time tracking.
The collected time is printed in block-nl-join.r_other_time_ms.

Reviewed by: Monty <monty@mariadb.org>

4 files changed, 22 insertions, 7 deletions

diff --git a/sql/sql_analyze_stmt.h b/sql/sql_analyze_stmt.h
index fdbd5955f33..e2037279a7a 100644
--- a/sql/sql_analyze_stmt.h
+++ b/sql/sql_analyze_stmt.h
@@ -63,14 +63,19 @@ protected:
     if (my_gap_tracker)
       attach_gap_time_tracker(thd, my_gap_tracker, end);
   }
-public:
-  Exec_time_tracker() : count(0), cycles(0), my_gap_tracker(NULL) {}
 
   /*
-    The time spent between stop_tracking() call on this object and any
-    other time measurement will be billed to this tracker.
+    The time spent after stop_tracking() call on this object and any
+    subsequent time tracking call will be billed to this tracker.
   */
   Gap_time_tracker *my_gap_tracker;
+public:
+  Exec_time_tracker() : count(0), cycles(0), my_gap_tracker(NULL) {}
+
+  void set_gap_tracker(Gap_time_tracker *gap_tracker)
+  {
+    my_gap_tracker= gap_tracker;
+  }
 
   // interface for collecting time
   void start_tracking(THD *thd)
diff --git a/sql/sql_explain.cc b/sql/sql_explain.cc
index e8f77317c84..2874417d8df 100644
--- a/sql/sql_explain.cc
+++ b/sql/sql_explain.cc
@@ -1901,6 +1901,9 @@ void Explain_table_access::print_explain_json(Explain_query *query,
 
       writer->add_member("r_unpack_time_ms");
       writer->add_double(jbuf_unpack_tracker.get_time_ms());
+
+      writer->add_member("r_other_time_ms").
+        add_double(jbuf_extra_time_tracker.get_time_ms());
       /*
         effective_rows is average number of matches we got for an incoming
         row. The row is stored in the join buffer and then is read
diff --git a/sql/sql_explain.h b/sql/sql_explain.h
index a80d4049e4c..84e2b1db89a 100644
--- a/sql/sql_explain.h
+++ b/sql/sql_explain.h
@@ -846,10 +846,15 @@ public:
   /* When using join buffer: Track the reads from join buffer */
   Table_access_tracker jbuf_tracker;
 
+  /* When using join buffer: time spent unpacking rows from the join buffer */
+  Time_and_counter_tracker jbuf_unpack_tracker;
+
   /*
-    Track the time to unpack rows from the join buffer.
+    When using join buffer: time spent after unpacking rows from the join
+    buffer. This will capture the time spent checking the Join Condition:
+    the condition that depends on this table and preceding tables.
   */
-  Time_and_counter_tracker jbuf_unpack_tracker;
+  Gap_time_tracker jbuf_extra_time_tracker;
 
   /* When using join buffer: Track the number of incoming record combinations */
   Counter_tracker jbuf_loops_tracker;
diff --git a/sql/sql_select.cc b/sql/sql_select.cc
index 4abf9f2fad6..8769a03404d 100644
--- a/sql/sql_select.cc
+++ b/sql/sql_select.cc
@@ -27402,7 +27402,9 @@ bool JOIN_TAB::save_explain_data(Explain_table_access *eta,
   if (thd->lex->analyze_stmt)
   {
     table->file->set_time_tracker(&eta->op_tracker);
-    eta->op_tracker.my_gap_tracker = &eta->extra_time_tracker;
+    eta->op_tracker.set_gap_tracker(&eta->extra_time_tracker);
+
+    eta->jbuf_unpack_tracker.set_gap_tracker(&eta->jbuf_extra_time_tracker);
   }
   /* No need to save id and select_type here, they are kept in Explain_select */