Bug #19764: SHOW commands end up in the slow log as table scans

Set a flag when a SHOW command is parsed, and check it in log_slow_statement().  SHOW commands are not counted as slow queries, even if they use table scans.


mysql-test/t/show_check-master.opt:
  BitKeeper file /usr/home/tim/m/bk/b19764/50/mysql-test/t/show_check-master.opt
mysql-test/r/show_check.result:
  Add test for bug #19764
mysql-test/t/show_check.test:
  Add test for bug #19764
sql/sql_lex.cc:
  Set lex->is_show_command= FALSE in lex_start
sql/sql_lex.h:
  Add LEX->is_slow_command flag to prevent SHOW commands from being written to the slow queries log
sql/sql_parse.cc:
  Don't log slow statement if it is a SHOW command
sql/sql_yacc.yy:
  Set lex->is_show_command for all SHOW commands

mysql-test/r/show_check.result

@@ -520,6 +520,7 @@ t1	NULL	NULL	NULL	NULL	#	#	#	#	NULL	NULL	NULL	NULL	NULL	NULL	NULL	NULL	Incorrect
 show create table t1;
 ERROR HY000: Incorrect information in file: './test/t1.frm'
 drop table t1;
+End of 4.1 tests
 CREATE TABLE txt1(a int);
 CREATE TABLE tyt2(a int);
 CREATE TABLE urkunde(a int);
@@ -629,3 +630,19 @@ SHOW TABLES FROM no_such_database;
 ERROR 42000: Unknown database 'no_such_database'
 SHOW COLUMNS FROM no_such_table;
 ERROR 42S02: Table 'test.no_such_table' doesn't exist
+flush status;
+show status like 'slow_queries';
+Variable_name	Value
+Slow_queries	0
+show tables;
+Tables_in_test
+show status like 'slow_queries';
+Variable_name	Value
+Slow_queries	0
+select 1 from information_schema.tables limit 1;
+1
+1
+show status like 'slow_queries';
+Variable_name	Value
+Slow_queries	1
+End of 5.0 tests.

mysql-test/t/show_check-master.opt

+--log-slow-queries --log-long-format --log-queries-not-using-indexes

mysql-test/t/show_check.test

@@ -400,7 +400,8 @@ show create table t1;
 drop table t1;
 
 
-# End of 4.1 tests
+--echo End of 4.1 tests
+
 #
 # BUG 12183 -  SHOW OPEN TABLES behavior doesn't match grammar
 # First we close all open tables with FLUSH tables and then we open some.
@@ -506,4 +507,16 @@ SHOW TABLES FROM no_such_database;
 SHOW COLUMNS FROM no_such_table;
 
 
-# End of 5.0 tests.
+#
+# Bug #19764: SHOW commands end up in the slow log as table scans
+#
+flush status;
+show status like 'slow_queries';
+show tables;
+show status like 'slow_queries';
+# Table scan query, to ensure that slow_queries does still get incremented
+# (mysqld is started with --log-queries-not-using-indexes)
+select 1 from information_schema.tables limit 1;
+show status like 'slow_queries';
+
+--echo End of 5.0 tests.

sql/sql_lex.cc

@@ -173,6 +173,7 @@ void lex_start(THD *thd, uchar *buf,uint length)
   lex->spcont= NULL;
   lex->proc_list.first= 0;
   lex->escape_used= FALSE;
+  lex->is_show_command= FALSE;
   lex->reset_query_tables_list(FALSE);
 
   lex->nest_level=0 ;

sql/sql_lex.h

@@ -1016,6 +1016,13 @@ typedef struct st_lex : public Query_tables_list
   
   bool escape_used;
 
+  /*
+    Prevent SHOW commands from being written to the slow queries log.
+    This is fixed properly in MySQL 5.1, but a quick hack is used in 5.0
+    to achieve the same result.
+  */
+  bool is_show_command;
+
   st_lex();
 
   virtual ~st_lex()

sql/sql_parse.cc

@@ -2150,10 +2150,10 @@ void log_slow_statement(THD *thd)
   thd->end_time();				// Set start time
 
   /*
-    Do not log administrative statements unless the appropriate option is
-    set; do not log into slow log if reading from backup.
+    Do not log administrative or SHOW statements unless the appropriate
+    option is set; do not log into slow log if reading from backup.
   */
-  if (thd->enable_slow_log && !thd->user_time)
+  if (thd->enable_slow_log && !thd->user_time && !thd->lex->is_show_command)
   {
     thd->proc_info="logging slow query";
 

sql/sql_yacc.yy

@@ -6412,6 +6412,7 @@ opt_table_sym:
 show:	SHOW
 	{
 	  LEX *lex=Lex;
+          lex->is_show_command= TRUE;
 	  lex->wild=0;
           lex->lock_option= TL_READ;
           mysql_init_select(lex);