List:Commits« Previous MessageNext Message »
From:tim Date:October 12 2006 11:10pm
Subject:bk commit into 5.0 tree (tsmith:1.2304) BUG#19764
View as plain text  
Below is the list of changes that have just been committed into a local
5.0 repository of tim. When tim does a push these changes will
be propagated to the main repository and, within 24 hours after the
push, to the public repository.
For information on how to access the public repository
see http://dev.mysql.com/doc/mysql/en/installing-source-tree.html

ChangeSet@stripped, 2006-10-12 17:10:34-06:00, tsmith@stripped +9 -0
  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/r/ps.result@stripped, 2006-10-12 17:10:30-06:00, tsmith@stripped +17 -0
    Add test case for bug 19764

  mysql-test/r/show_check.result@stripped, 2006-10-12 17:10:30-06:00, tsmith@stripped +15 -0
    Add test case for bug 19764

  mysql-test/r/union.result@stripped, 2006-10-12 17:10:30-06:00, tsmith@stripped +4 -4
    Adjust test case results based on bug #19764 changes

  mysql-test/t/ps-master.opt@stripped, 2006-10-12 17:10:30-06:00, tsmith@stripped +1 -0
    Add log-slow-queries and --log-queries-not-using indexes, to test bug #19764

  mysql-test/t/ps-master.opt@stripped, 2006-10-12 17:10:30-06:00, tsmith@stripped +0 -0

  mysql-test/t/ps.test@stripped, 2006-10-12 17:10:30-06:00, tsmith@stripped +14 -0
    Add test case for bug 19764

  mysql-test/t/show_check-master.opt@stripped, 2006-10-12 13:48:09-06:00, tsmith@stripped +0 -0
    Rename: BitKeeper/deleted/.del-show_check-master.opt -> mysql-test/t/show_check-master.opt

  mysql-test/t/show_check.test@stripped, 2006-10-12 17:10:30-06:00, tsmith@stripped +12 -0
    Add test case for bug 19764

  sql/sql_parse.cc@stripped, 2006-10-12 17:10:30-06:00, tsmith@stripped +4 -2
    Do not log SHOW commands as slow queries just because they don't use indexes.

  sql/sql_prepare.cc@stripped, 2006-10-12 17:10:30-06:00, tsmith@stripped +6 -0
    Save stmt_backup.lex->orig_sql_command for use in log_slow_statement()

# This is a BitKeeper patch.  What follows are the unified diffs for the
# set of deltas contained in the patch.  The rest of the patch, the part
# that BitKeeper cares about, is below these diffs.
# User:	tsmith
# Host:	siva.hindu.god
# Root:	/usr/home/tim/m/bk/b19764/50

--- 1.582/sql/sql_parse.cc	2006-10-12 17:10:43 -06:00
+++ 1.583/sql/sql_parse.cc	2006-10-12 17:10:43 -06:00
@@ -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);

--- 1.86/mysql-test/r/union.result	2006-10-12 17:10:43 -06:00
+++ 1.87/mysql-test/r/union.result	2006-10-12 17:10:43 -06:00
@@ -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

--- 1.80/mysql-test/r/show_check.result	2006-10-12 17:10:43 -06:00
+++ 1.81/mysql-test/r/show_check.result	2006-10-12 17:10:43 -06:00
@@ -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

--- 1.60/mysql-test/t/show_check.test	2006-10-12 17:10:43 -06:00
+++ 1.61/mysql-test/t/show_check.test	2006-10-12 17:10:43 -06:00
@@ -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

--- 1.74/mysql-test/r/ps.result	2006-10-12 17:10:43 -06:00
+++ 1.75/mysql-test/r/ps.result	2006-10-12 17:10:43 -06:00
@@ -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.

--- 1.71/mysql-test/t/ps.test	2006-10-12 17:10:43 -06:00
+++ 1.72/mysql-test/t/ps.test	2006-10-12 17:10:43 -06:00
@@ -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.
--- New file ---
+++ mysql-test/t/ps-master.opt	06/10/12 17:10:30
--log-slow-queries --log-long-format --log-queries-not-using-indexes


--- 1.182/sql/sql_prepare.cc	2006-10-12 17:10:43 -06:00
+++ 1.183/sql/sql_prepare.cc	2006-10-12 17:10:43 -06:00
@@ -2909,6 +2909,12 @@ bool Prepared_statement::execute(String 
   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
     on the parse tree of current prepared statement and new items should
Thread
bk commit into 5.0 tree (tsmith:1.2304) BUG#19764tim13 Oct