MDEV-20854: ANALYZE for statements: not clear where the time is spent

Count the "gap" time between table accesses and display it as
r_other_time_ms in the "table" element.

* The advantage of this approach is that it doesn't add any new
  my_timer_cycles() calls.
* The disadvantage is that the definition of what is done during
  "other time" is not that clear: it includes checking the WHERE
  (for this table), constructing index lookup tuple (for the next table)
  writing to GROUP BY temporary table (as we dont account for that time
  separately [yet], etc)

1 files changed, 50 insertions, 25 deletions

diff --git a/mysql-test/main/analyze_format_json.result b/mysql-test/main/analyze_format_json.result
index c306c2fc1b3..ccef3a63592 100644
--- a/mysql-test/main/analyze_format_json.result
+++ b/mysql-test/main/analyze_format_json.result
@@ -15,7 +15,8 @@ ANALYZE
       "r_loops": 1,
       "rows": 10,
       "r_rows": 10,
-      "r_total_time_ms": "REPLACED",
+      "r_table_time_ms": "REPLACED",
+      "r_other_time_ms": "REPLACED",
       "filtered": 100,
       "r_filtered": 30,
       "attached_condition": "t0.a < 3"
@@ -43,7 +44,8 @@ ANALYZE
       "r_loops": 1,
       "rows": 10,
       "r_rows": 10,
-      "r_total_time_ms": "REPLACED",
+      "r_table_time_ms": "REPLACED",
+      "r_other_time_ms": "REPLACED",
       "filtered": 100,
       "r_filtered": 0,
       "attached_condition": "t0.a > 9 and t0.a is not null"
@@ -83,7 +85,8 @@ ANALYZE
       "r_loops": 1,
       "rows": 10,
       "r_rows": 10,
-      "r_total_time_ms": "REPLACED",
+      "r_table_time_ms": "REPLACED",
+      "r_other_time_ms": "REPLACED",
       "filtered": 100,
       "r_filtered": 100,
       "attached_condition": "t0.a is not null"
@@ -99,7 +102,8 @@ ANALYZE
       "r_loops": 10,
       "rows": 1,
       "r_rows": 1,
-      "r_total_time_ms": "REPLACED",
+      "r_table_time_ms": "REPLACED",
+      "r_other_time_ms": "REPLACED",
       "filtered": 100,
       "r_filtered": 40,
       "attached_condition": "t1.b < 4"
@@ -125,7 +129,8 @@ ANALYZE
       "r_loops": 1,
       "rows": 100,
       "r_rows": 100,
-      "r_total_time_ms": "REPLACED",
+      "r_table_time_ms": "REPLACED",
+      "r_other_time_ms": "REPLACED",
       "filtered": 100,
       "r_filtered": 20,
       "attached_condition": "tbl1.b < 20"
@@ -137,7 +142,8 @@ ANALYZE
         "r_loops": 1,
         "rows": 100,
         "r_rows": 100,
-        "r_total_time_ms": "REPLACED",
+        "r_table_time_ms": "REPLACED",
+        "r_other_time_ms": "REPLACED",
         "filtered": 100,
         "r_filtered": 60,
         "attached_condition": "tbl2.b < 60"
@@ -163,7 +169,8 @@ ANALYZE
       "r_loops": 1,
       "rows": 100,
       "r_rows": 100,
-      "r_total_time_ms": "REPLACED",
+      "r_table_time_ms": "REPLACED",
+      "r_other_time_ms": "REPLACED",
       "filtered": 100,
       "r_filtered": 20,
       "attached_condition": "tbl1.b < 20"
@@ -175,7 +182,8 @@ ANALYZE
         "r_loops": 1,
         "rows": 100,
         "r_rows": 100,
-        "r_total_time_ms": "REPLACED",
+        "r_table_time_ms": "REPLACED",
+        "r_other_time_ms": "REPLACED",
         "filtered": 100,
         "r_filtered": 60,
         "attached_condition": "tbl2.b < 60"
@@ -210,7 +218,8 @@ ANALYZE
       "r_loops": 1,
       "rows": 10,
       "r_rows": 10,
-      "r_total_time_ms": "REPLACED",
+      "r_table_time_ms": "REPLACED",
+      "r_other_time_ms": "REPLACED",
       "filtered": 100,
       "r_filtered": 100,
       "attached_condition": "t1.a is not null"
@@ -226,7 +235,8 @@ ANALYZE
       "r_loops": 10,
       "rows": 2,
       "r_rows": 0.2,
-      "r_total_time_ms": "REPLACED",
+      "r_table_time_ms": "REPLACED",
+      "r_other_time_ms": "REPLACED",
       "filtered": 100,
       "r_filtered": 100,
       "using_index": true
@@ -260,7 +270,8 @@ ANALYZE
       "r_loops": 1,
       "rows": 10,
       "r_rows": 10,
-      "r_total_time_ms": "REPLACED",
+      "r_table_time_ms": "REPLACED",
+      "r_other_time_ms": "REPLACED",
       "filtered": 100,
       "r_filtered": 50,
       "attached_condition": "test.t1.a < 5"
@@ -317,7 +328,8 @@ ANALYZE
       "r_loops": 1,
       "rows": 10,
       "r_rows": 10,
-      "r_total_time_ms": "REPLACED",
+      "r_table_time_ms": "REPLACED",
+      "r_other_time_ms": "REPLACED",
       "filtered": 100,
       "r_filtered": 50,
       "index_condition": "t1.pk < 10",
@@ -382,7 +394,8 @@ ANALYZE
       "r_loops": 1,
       "rows": 5,
       "r_rows": 5,
-      "r_total_time_ms": "REPLACED",
+      "r_table_time_ms": "REPLACED",
+      "r_other_time_ms": "REPLACED",
       "filtered": 100,
       "r_filtered": 100
     },
@@ -405,7 +418,8 @@ ANALYZE
         "r_loops": 5,
         "rows": 1010,
         "r_rows": 203.8,
-        "r_total_time_ms": "REPLACED",
+        "r_table_time_ms": "REPLACED",
+        "r_other_time_ms": "REPLACED",
         "filtered": 100,
         "r_filtered": 98.135
       }
@@ -441,7 +455,8 @@ ANALYZE
               "r_loops": 1,
               "rows": 10,
               "r_rows": 10,
-              "r_total_time_ms": "REPLACED",
+              "r_table_time_ms": "REPLACED",
+              "r_other_time_ms": "REPLACED",
               "filtered": 100,
               "r_filtered": 50,
               "attached_condition": "tbl1.a < 5"
@@ -460,7 +475,8 @@ ANALYZE
               "r_loops": 1,
               "rows": 10,
               "r_rows": 10,
-              "r_total_time_ms": "REPLACED",
+              "r_table_time_ms": "REPLACED",
+              "r_other_time_ms": "REPLACED",
               "filtered": 100,
               "r_filtered": 20,
               "attached_condition": "tbl2.a in (2,3)"
@@ -508,7 +524,8 @@ ANALYZE
           "r_loops": 1,
           "rows": 256,
           "r_rows": 256,
-          "r_total_time_ms": "REPLACED",
+          "r_table_time_ms": "REPLACED",
+          "r_other_time_ms": "REPLACED",
           "filtered": 100,
           "r_filtered": 100
         }
@@ -538,7 +555,8 @@ ANALYZE
           "r_loops": 1,
           "rows": 256,
           "r_rows": 256,
-          "r_total_time_ms": "REPLACED",
+          "r_table_time_ms": "REPLACED",
+          "r_other_time_ms": "REPLACED",
           "filtered": 100,
           "r_filtered": 100
         }
@@ -579,7 +597,8 @@ ANALYZE
           "r_loops": 1,
           "rows": 256,
           "r_rows": 256,
-          "r_total_time_ms": "REPLACED",
+          "r_table_time_ms": "REPLACED",
+          "r_other_time_ms": "REPLACED",
           "filtered": 100,
           "r_filtered": 100
         }
@@ -608,7 +627,8 @@ ANALYZE
       "r_loops": 1,
       "rows": 2,
       "r_rows": 2,
-      "r_total_time_ms": "REPLACED",
+      "r_table_time_ms": "REPLACED",
+      "r_other_time_ms": "REPLACED",
       "filtered": 100,
       "r_filtered": 100
     },
@@ -619,7 +639,8 @@ ANALYZE
         "r_loops": 1,
         "rows": 2,
         "r_rows": 2,
-        "r_total_time_ms": "REPLACED",
+        "r_table_time_ms": "REPLACED",
+        "r_other_time_ms": "REPLACED",
         "filtered": 100,
         "r_filtered": 0,
         "attached_condition": "<in_optimizer>(t2.b,t2.b in (subquery#2))"
@@ -642,7 +663,8 @@ ANALYZE
             "r_loops": 1,
             "rows": 2,
             "r_rows": 2,
-            "r_total_time_ms": "REPLACED",
+            "r_table_time_ms": "REPLACED",
+            "r_other_time_ms": "REPLACED",
             "filtered": 100,
             "r_filtered": 100
           }
@@ -694,7 +716,8 @@ ANALYZE
               "r_loops": 1,
               "rows": 2,
               "r_rows": 2,
-              "r_total_time_ms": "REPLACED",
+              "r_table_time_ms": "REPLACED",
+              "r_other_time_ms": "REPLACED",
               "filtered": 100,
               "r_filtered": 100
             },
@@ -705,7 +728,8 @@ ANALYZE
                 "r_loops": 1,
                 "rows": 2,
                 "r_rows": 2,
-                "r_total_time_ms": "REPLACED",
+                "r_table_time_ms": "REPLACED",
+                "r_other_time_ms": "REPLACED",
                 "filtered": 100,
                 "r_filtered": 0,
                 "attached_condition": "t3.f3 in (1,2)"
@@ -779,7 +803,8 @@ ANALYZE
       "r_loops": 1,
       "rows": 10,
       "r_rows": 10,
-      "r_total_time_ms": "REPLACED",
+      "r_table_time_ms": "REPLACED",
+      "r_other_time_ms": "REPLACED",
       "filtered": 100,
       "r_filtered": 0,
       "attached_condition": "t1.a < 0"