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

Do not consider SHOW commands slow queries, just because they don't use proper indexes.

This bug fix is not needed in 5.1, and the code changes will be null merged.  However, the test cases will be propogated up to 5.1.


mysql-test/t/show_check-master.opt:
  Rename: BitKeeper/deleted/.del-show_check-master.opt -> mysql-test/t/show_check-master.opt
mysql-test/r/ps.result:
  Add test case for bug 19764
mysql-test/r/show_check.result:
  Add test case for bug 19764
mysql-test/r/union.result:
  Adjust test case results based on bug #19764 changes
mysql-test/t/ps.test:
  Add test case for bug 19764
mysql-test/t/show_check.test:
  Add test case for bug 19764
sql/sql_parse.cc:
  Do not log SHOW commands as slow queries just because they don't use indexes.
sql/sql_prepare.cc:
  Save stmt_backup.lex->orig_sql_command for use in log_slow_statement()
mysql-test/t/ps-master.opt:
  Add log-slow-queries and --log-queries-not-using indexes, to test bug #19764

mysql-test/r/ps.result

@@ -1358,4 +1358,21 @@ EXECUTE stmt USING @a;
 i	j	i	i	j
 DEALLOCATE PREPARE stmt;
 DROP TABLE IF EXISTS t1, t2, t3;
+flush status;
+prepare sq from 'show status like "slow_queries"';
+execute sq;
+Variable_name	Value
+Slow_queries	0
+prepare no_index from 'select 1 from information_schema.tables limit 1';
+execute sq;
+Variable_name	Value
+Slow_queries	0
+execute no_index;
+1
+1
+execute sq;
+Variable_name	Value
+Slow_queries	1
+deallocate prepare no_index;
+deallocate prepare sq;
 End of 5.0 tests.

mysql-test/r/show_check.result

@@ -630,4 +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/r/union.result

@@ -836,27 +836,27 @@ count(*)
 26
 show status like 'Slow_queries';
 Variable_name	Value
-Slow_queries	1
+Slow_queries	0
 select count(*) from t1 where b=13;
 count(*)
 10
 show status like 'Slow_queries';
 Variable_name	Value
-Slow_queries	3
+Slow_queries	1
 select count(*) from t1 where b=13 union select count(*) from t1 where a=7;
 count(*)
 10
 26
 show status like 'Slow_queries';
 Variable_name	Value
-Slow_queries	5
+Slow_queries	2
 select count(*) from t1 where a=7 union select count(*) from t1 where b=13;
 count(*)
 26
 10
 show status like 'Slow_queries';
 Variable_name	Value
-Slow_queries	7
+Slow_queries	3
 flush status;
 select a from t1 where b not in (1,2,3) union select a from t1 where b not in (4,5,6);
 a

mysql-test/t/ps-master.opt

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

mysql-test/t/ps.test

@@ -1410,4 +1410,18 @@ DEALLOCATE PREPARE stmt;
 DROP TABLE IF EXISTS t1, t2, t3;
 
 
+#
+# Bug 19764:  SHOW commands end up in the slow log as table scans
+#
+
+flush status;
+prepare sq from 'show status like "slow_queries"';
+execute sq;
+prepare no_index from 'select 1 from information_schema.tables limit 1';
+execute sq;
+execute no_index;
+execute sq;
+deallocate prepare no_index;
+deallocate prepare sq;
+
 --echo 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

@@ -507,4 +507,16 @@ SHOW TABLES FROM no_such_database;
 SHOW COLUMNS FROM no_such_table;
 
 
+#
+# 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_parse.cc

@@ -2159,9 +2159,11 @@ void log_slow_statement(THD *thd)
 
     if ((ulong) (thd->start_time - thd->time_after_lock) >
 	thd->variables.long_query_time ||
-	((thd->server_status &
+        (thd->server_status &
 	  (SERVER_QUERY_NO_INDEX_USED | SERVER_QUERY_NO_GOOD_INDEX_USED)) &&
-	 (specialflag & SPECIAL_LOG_QUERIES_NOT_USING_INDEXES)))
+        (specialflag & SPECIAL_LOG_QUERIES_NOT_USING_INDEXES) &&
+        /* == SQLCOM_END unless this is a SHOW command */
+        thd->lex->orig_sql_command == SQLCOM_END)
     {
       thd->status_var.long_query_count++;
       mysql_slow_log.write(thd, thd->query, thd->query_length, start_of_query);

sql/sql_prepare.cc

@@ -2908,6 +2908,12 @@ bool Prepared_statement::execute(String *expanded_query, bool open_cursor)
   stmt_backup.query= thd->query;
   stmt_backup.query_length= thd->query_length;
 
+  /*
+    Save orig_sql_command as we use it to disable slow logging for SHOW
+    commands (see log_slow_statement()).
+  */
+  stmt_backup.lex->orig_sql_command= thd->lex->orig_sql_command;
+
   /*
     At first execution of prepared statement we may perform logical
     transformations of the query tree. Such changes should be performed