MDEV-5045: Server crashes in QPF_query::print_explain with log_slow_verbosity='explain'

- Don't print a plan when the statement didn't produce it
- Also, add first testcase. We can't check the EXPLAIN from the slow log itself, though.

6 files changed, 41 insertions, 6 deletions

diff --git a/mysql-test/r/explain_slowquerylog.result b/mysql-test/r/explain_slowquerylog.result
new file mode 100644
index 00000000000..86e1ca391d6
--- /dev/null
+++ b/mysql-test/r/explain_slowquerylog.result
@@ -0,0 +1,11 @@
+drop table if exists t0,t1;
+create table t0 (a int);
+insert into t0 values (0),(1),(2),(3),(4),(5),(6),(7),(8),(9);
+explain select * from t0 where a < 3;
+id	select_type	table	type	possible_keys	key	key_len	ref	rows	Extra
+1	SIMPLE	t0	ALL	NULL	NULL	NULL	NULL	10	Using where
+# 
+# MDEV-5045: Server crashes in QPF_query::print_explain with log_slow_verbosity='query_plan,explain'
+# 
+set autocommit=1;
+drop table t0;
diff --git a/mysql-test/t/explain_slowquerylog-master.opt b/mysql-test/t/explain_slowquerylog-master.opt
new file mode 100644
index 00000000000..0a3ad969e79
--- /dev/null
+++ b/mysql-test/t/explain_slowquerylog-master.opt
@@ -0,0 +1 @@
+--slow-query-log --long-query-time=0.00000 --log-slow-verbosity=query_plan,explain
diff --git a/mysql-test/t/explain_slowquerylog.test b/mysql-test/t/explain_slowquerylog.test
new file mode 100644
index 00000000000..64005d98d05
--- /dev/null
+++ b/mysql-test/t/explain_slowquerylog.test
@@ -0,0 +1,20 @@
+#
+# This is a test for EXPLAINs being written into slow query log.
+# For now, we just run the queries and hope not to crash.
+# 
+#
+--disable_warnings
+drop table if exists t0,t1;
+--enable_warnings
+
+create table t0 (a int);
+insert into t0 values (0),(1),(2),(3),(4),(5),(6),(7),(8),(9);
+
+explain select * from t0 where a < 3;
+
+--echo # 
+--echo # MDEV-5045: Server crashes in QPF_query::print_explain with log_slow_verbosity='query_plan,explain'
+--echo # 
+set autocommit=1;
+
+drop table t0;
diff --git a/sql/log.cc b/sql/log.cc
index 5d8b650b494..3f782a478bb 100644
--- a/sql/log.cc
+++ b/sql/log.cc
@@ -2830,8 +2830,8 @@ bool MYSQL_QUERY_LOG::write(THD *thd, time_t current_time,
     {
       StringBuffer<128> buf;
       DBUG_ASSERT(!thd->free_list);
-      print_qpf_query(thd->lex, thd, &buf);
-      my_b_printf(&log_file, "%s", buf.c_ptr_safe());
+      if (!print_qpf_query(thd->lex, thd, &buf))
+        my_b_printf(&log_file, "%s", buf.c_ptr_safe());
       thd->free_items();
     }
     if (thd->db && strcmp(thd->db, db))
diff --git a/sql/opt_qpf.cc b/sql/opt_qpf.cc
index fc2597bcd73..0f047f05ba0 100644
--- a/sql/opt_qpf.cc
+++ b/sql/opt_qpf.cc
@@ -116,13 +116,15 @@ int QPF_query::print_explain(select_result_sink *output,
   {
     /* Start printing from node with id=1 */
     QPF_node *node= get_node(1);
+    if (!node)
+      return 1; /* No query plan */
     return node->print_explain(this, output, explain_flags);
   }
 }
 
-void print_qpf_query(LEX *lex, THD *thd, String *str)
+bool print_qpf_query(LEX *lex, THD *thd, String *str)
 {
-  lex->query_plan_footprint->print_explain_str(thd, str);
+  return lex->query_plan_footprint->print_explain_str(thd, str);
 }
 
 bool QPF_query::print_explain_str(THD *thd, String *out_str)
@@ -132,7 +134,8 @@ bool QPF_query::print_explain_str(THD *thd, String *out_str)
 
   select_result_text_buffer output_buf(thd);
   output_buf.send_result_set_metadata(fields, thd->lex->describe);
-  print_explain(&output_buf, 0);
+  if (print_explain(&output_buf, 0))
+    return true;
   output_buf.save_to(out_str);
   return false;
 }
diff --git a/sql/sql_lex.h b/sql/sql_lex.h
index 77f0054d122..13140063bff 100644
--- a/sql/sql_lex.h
+++ b/sql/sql_lex.h
@@ -622,7 +622,7 @@ class QPF_query;
 
 void delete_qpf_query(LEX *lex);
 void create_qpf_query(LEX *lex, MEM_ROOT *mem_root);
-void print_qpf_query(LEX *lex, THD *thd, String *str);
+bool print_qpf_query(LEX *lex, THD *thd, String *str);
 
 class st_select_lex_unit: public st_select_lex_node {
 protected: