MDEV-32351: Significant slowdown with outer joins: Test coverage

Make ANALYZE FORMAT=JSON print block-nl-join.r_unpack_ops when
analyze_print_r_unpack_ops debug flag is set.

Then, add a testcase.

mysql-test/main/join_cache_debug.result

@@ -0,0 +1,101 @@
+#
+# MDEV-32351: Significant slowdown for query with many outer joins
+#
+CREATE TABLE t1 (b int NOT NULL, PRIMARY KEY (b)) ENGINE=MYISAM;
+INSERT INTO t1 select seq from seq_1_to_10000;
+CREATE TABLE t2 (b int NOT NULL, d varchar(255), KEY (b)) ENGINE=MYISAM ;
+INSERT INTO t2 VALUES (1,1),(2,2),(3,3);
+CREATE TABLE t3 (c int NOT NULL, PRIMARY KEY (c)) ENGINE=MYISAM ;
+INSERT INTO t3 select seq from seq_1_to_3000;
+CREATE TABLE t4 (c int NOT NULL, PRIMARY KEY (c)) ENGINE=MYISAM;
+INSERT INTO t4 select seq from seq_1_to_3000;
+ANALYZE TABLE t1,t2,t3,t4;
+Table	Op	Msg_type	Msg_text
+test.t1	analyze	status	Engine-independent statistics collected
+test.t1	analyze	status	OK
+test.t2	analyze	status	Engine-independent statistics collected
+test.t2	analyze	status	OK
+test.t3	analyze	status	Engine-independent statistics collected
+test.t3	analyze	status	OK
+test.t4	analyze	status	Engine-independent statistics collected
+test.t4	analyze	status	OK
+create table t1_t2 as
+select 
+t1.b as t1_b, t2.b as t2_b, t2.d as t2_d
+FROM t1
+LEFT JOIN t2 ON t1.b = t2.b;
+SET @old_debug=@@debug_dbug;
+SET debug_dbug='+d,analyze_print_r_unpack_ops';
+analyze
+format=json
+SELECT COUNT(*)
+FROM t1_t2
+LEFT JOIN t3 ON t2_d = t3.c
+LEFT JOIN t4 ON t3.c=1
+select '$js' as JSON;
+JSON
+{
+  "query_block": {
+    "select_id": 1,
+    "r_loops": 1,
+    "r_total_time_ms": "REPLACED",
+    "const_condition": "1",
+    "table": {
+      "table_name": "t1_t2",
+      "access_type": "ALL",
+      "r_loops": 1,
+      "rows": 10000,
+      "r_rows": 10000,
+      "r_total_time_ms": "REPLACED",
+      "filtered": 100,
+      "r_filtered": 100
+    },
+    "table": {
+      "table_name": "t3",
+      "access_type": "eq_ref",
+      "possible_keys": ["PRIMARY"],
+      "key": "PRIMARY",
+      "key_length": "4",
+      "used_key_parts": ["c"],
+      "ref": ["test.t1_t2.t2_d"],
+      "r_loops": 10000,
+      "rows": 1,
+      "r_rows": 0.0003,
+      "r_total_time_ms": "REPLACED",
+      "filtered": 100,
+      "r_filtered": 100,
+      "attached_condition": "trigcond(t1_t2.t2_d = t3.c and trigcond(t1_t2.t2_d is not null))",
+      "using_index": true
+    },
+    "block-nl-join": {
+      "table": {
+        "table_name": "t4",
+        "access_type": "index",
+        "key": "PRIMARY",
+        "key_length": "4",
+        "used_key_parts": ["c"],
+        "r_loops": 1,
+        "rows": 3000,
+        "r_rows": 3000,
+        "r_total_time_ms": "REPLACED",
+        "filtered": 100,
+        "r_filtered": 100,
+        "using_index": true
+      },
+      "buffer_type": "flat",
+      "buffer_size": "256Kb",
+      "join_type": "BNL",
+      "attached_condition": "trigcond(trigcond(t3.c = 1))",
+      "r_filtered": 0.0433,
+      "r_unpack_time_ms": "REPLACED",
+      "r_unpack_ops": 3000
+    }
+  }
+}
+# This must show 3000, not 30000000:
+select json_extract('$js', '\$**.r_unpack_ops') as R_UNPACK_OPS;
+R_UNPACK_OPS
+[3000]
+SET debug_dbug=@old_debug;
+drop table t1,t2,t3,t4;
+drop table t1_t2;

mysql-test/main/join_cache_debug.test

@@ -0,0 +1,44 @@
+--source include/have_sequence.inc
+--source include/have_debug.inc
+
+--echo #
+--echo # MDEV-32351: Significant slowdown for query with many outer joins
+--echo #
+CREATE TABLE t1 (b int NOT NULL, PRIMARY KEY (b)) ENGINE=MYISAM;
+INSERT INTO t1 select seq from seq_1_to_10000;
+CREATE TABLE t2 (b int NOT NULL, d varchar(255), KEY (b)) ENGINE=MYISAM ;
+INSERT INTO t2 VALUES (1,1),(2,2),(3,3);
+CREATE TABLE t3 (c int NOT NULL, PRIMARY KEY (c)) ENGINE=MYISAM ;
+INSERT INTO t3 select seq from seq_1_to_3000;
+CREATE TABLE t4 (c int NOT NULL, PRIMARY KEY (c)) ENGINE=MYISAM;
+INSERT INTO t4 select seq from seq_1_to_3000;
+ANALYZE TABLE t1,t2,t3,t4;
+
+create table t1_t2 as
+select 
+  t1.b as t1_b, t2.b as t2_b, t2.d as t2_d
+FROM t1
+     LEFT JOIN t2 ON t1.b = t2.b;
+
+SET @old_debug=@@debug_dbug;
+SET debug_dbug='+d,analyze_print_r_unpack_ops';
+
+let $q= analyze
+format=json
+SELECT COUNT(*)
+FROM t1_t2
+     LEFT JOIN t3 ON t2_d = t3.c
+     LEFT JOIN t4 ON t3.c=1;
+
+echo $q;
+let $js=`$q`;
+
+--source include/analyze-format.inc
+evalp select '$js' as JSON;
+
+--echo # This must show 3000, not 30000000:
+evalp select json_extract('$js', '\$**.r_unpack_ops') as R_UNPACK_OPS;
+SET debug_dbug=@old_debug;
+
+drop table t1,t2,t3,t4;
+drop table t1_t2;

sql/sql_explain.cc

@@ -1907,6 +1907,11 @@ 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());
+      DBUG_EXECUTE_IF("analyze_print_r_unpack_ops",
+                      {
+                        writer->add_member("r_unpack_ops");
+                        writer->add_ull(jbuf_unpack_tracker.get_loops());
+                      });
     }
   }