Commit 44fe4c70 authored by Staale Smedseng's avatar Staale Smedseng

Bug #49756 Rows_examined is always 0 in the slow query log for

update statements
      
Only SELECT statements report any examined rows in the slow
log. Slow UPDATE, DELETE and INSERT statements report 0 rows
examined, unless the statement has a condition including a
SELECT substatement.
      
This patch adds counting of examined rows for the UPDATE and
DELETE statements. An INSERT ... VALUES statement will still 
not report any rows as examined.
parent b0b0000d
...@@ -308,8 +308,41 @@ SET @@global.general_log = @old_general_log; ...@@ -308,8 +308,41 @@ SET @@global.general_log = @old_general_log;
SET @@global.general_log_file = @old_general_log_file; SET @@global.general_log_file = @old_general_log_file;
SET @@global.slow_query_log = @old_slow_query_log; SET @@global.slow_query_log = @old_slow_query_log;
SET @@global.slow_query_log_file = @old_slow_query_log_file; SET @@global.slow_query_log_file = @old_slow_query_log_file;
#
# Bug #49756 Rows_examined is always 0 in the slow query log
# for update statements
#
SET @old_log_output = @@global.log_output;
SET GLOBAL log_output = "TABLE";
SET GLOBAL slow_query_log = ON;
SET GLOBAL long_query_time = 0.001;
TRUNCATE TABLE mysql.slow_log;
CREATE TABLE t1 (a INT);
CREATE TABLE t2 (b INT, PRIMARY KEY (b));
INSERT INTO t2 VALUES (3),(4);
INSERT INTO t1 VALUES (1+sleep(.01)),(2);
INSERT INTO t1 SELECT b+sleep(.01) from t2;
UPDATE t1 SET a=a+sleep(.01) WHERE a>2;
UPDATE t1 SET a=a+sleep(.01) ORDER BY a DESC;
UPDATE t2 set b=b+sleep(.01) limit 1;
UPDATE t1 SET a=a+sleep(.01) WHERE a in (SELECT b from t2);
DELETE FROM t1 WHERE a=a+sleep(.01) ORDER BY a LIMIT 2;
SELECT rows_examined,sql_text FROM mysql.slow_log;
rows_examined sql_text
0 INSERT INTO t1 VALUES (1+sleep(.01)),(2)
2 INSERT INTO t1 SELECT b+sleep(.01) from t2
4 UPDATE t1 SET a=a+sleep(.01) WHERE a>2
8 UPDATE t1 SET a=a+sleep(.01) ORDER BY a DESC
2 UPDATE t2 set b=b+sleep(.01) limit 1
4 UPDATE t1 SET a=a+sleep(.01) WHERE a in (SELECT b from t2)
6 DELETE FROM t1 WHERE a=a+sleep(.01) ORDER BY a LIMIT 2
DROP TABLE t1,t2;
TRUNCATE TABLE mysql.slow_log;
# end of bug#49756
End of 5.1 tests End of 5.1 tests
# Close connection con1 # Close connection con1
SET GLOBAL long_query_time = DEFAULT;
SET GLOBAL log_output = @old_log_output;
SET global general_log = @old_general_log; SET global general_log = @old_general_log;
SET global general_log_file = @old_general_log_file; SET global general_log_file = @old_general_log_file;
SET global slow_query_log = @old_slow_query_log; SET global slow_query_log = @old_slow_query_log;
......
...@@ -362,6 +362,42 @@ if(!$fixed_bug38124) ...@@ -362,6 +362,42 @@ if(!$fixed_bug38124)
} }
###########################################################################
--echo #
--echo # Bug #49756 Rows_examined is always 0 in the slow query log
--echo # for update statements
--echo #
SET @old_log_output = @@global.log_output;
SET GLOBAL log_output = "TABLE";
SET GLOBAL slow_query_log = ON;
SET GLOBAL long_query_time = 0.001;
# clear slow_log of any residual slow queries
TRUNCATE TABLE mysql.slow_log;
CREATE TABLE t1 (a INT);
CREATE TABLE t2 (b INT, PRIMARY KEY (b));
INSERT INTO t2 VALUES (3),(4);
connect (con2,localhost,root,,);
INSERT INTO t1 VALUES (1+sleep(.01)),(2);
INSERT INTO t1 SELECT b+sleep(.01) from t2;
UPDATE t1 SET a=a+sleep(.01) WHERE a>2;
UPDATE t1 SET a=a+sleep(.01) ORDER BY a DESC;
UPDATE t2 set b=b+sleep(.01) limit 1;
UPDATE t1 SET a=a+sleep(.01) WHERE a in (SELECT b from t2);
DELETE FROM t1 WHERE a=a+sleep(.01) ORDER BY a LIMIT 2;
SELECT rows_examined,sql_text FROM mysql.slow_log;
disconnect con2;
connection default;
DROP TABLE t1,t2;
TRUNCATE TABLE mysql.slow_log;
--echo # end of bug#49756
--echo End of 5.1 tests --echo End of 5.1 tests
--enable_ps_protocol --enable_ps_protocol
...@@ -376,6 +412,8 @@ disconnect con1; ...@@ -376,6 +412,8 @@ disconnect con1;
connection default; connection default;
# Reset global system variables to initial values if forgotten somewhere above. # Reset global system variables to initial values if forgotten somewhere above.
SET GLOBAL long_query_time = DEFAULT;
SET GLOBAL log_output = @old_log_output;
SET global general_log = @old_general_log; SET global general_log = @old_general_log;
SET global general_log_file = @old_general_log_file; SET global general_log_file = @old_general_log_file;
SET global slow_query_log = @old_slow_query_log; SET global slow_query_log = @old_slow_query_log;
......
...@@ -1716,8 +1716,15 @@ class THD :public Statement, ...@@ -1716,8 +1716,15 @@ class THD :public Statement,
*/ */
ha_rows sent_row_count; ha_rows sent_row_count;
/* /**
number of rows we read, sent or not, including in create_sort_index() Number of rows read and/or evaluated for a statement. Used for
slow log reporting.
An examined row is defined as a row that is read and/or evaluated
according to a statement condition, including in
create_sort_index(). Rows may be counted more than once, e.g., a
statement including ORDER BY could possibly evaluate the row in
filesort() before reading it for e.g. update.
*/ */
ha_rows examined_row_count; ha_rows examined_row_count;
......
...@@ -248,6 +248,7 @@ bool mysql_delete(THD *thd, TABLE_LIST *table_list, COND *conds, ...@@ -248,6 +248,7 @@ bool mysql_delete(THD *thd, TABLE_LIST *table_list, COND *conds,
free_underlaid_joins(thd, &thd->lex->select_lex); free_underlaid_joins(thd, &thd->lex->select_lex);
DBUG_RETURN(TRUE); DBUG_RETURN(TRUE);
} }
thd->examined_row_count+= examined_rows;
/* /*
Filesort has already found and selected the rows we want to delete, Filesort has already found and selected the rows we want to delete,
so we don't need the where clause so we don't need the where clause
...@@ -304,6 +305,7 @@ bool mysql_delete(THD *thd, TABLE_LIST *table_list, COND *conds, ...@@ -304,6 +305,7 @@ bool mysql_delete(THD *thd, TABLE_LIST *table_list, COND *conds,
while (!(error=info.read_record(&info)) && !thd->killed && while (!(error=info.read_record(&info)) && !thd->killed &&
! thd->is_error()) ! thd->is_error())
{ {
thd->examined_row_count++;
// thd->is_error() is tested to disallow delete row on error // thd->is_error() is tested to disallow delete row on error
if (!(select && select->skip_record())&& ! thd->is_error() ) if (!(select && select->skip_record())&& ! thd->is_error() )
{ {
......
...@@ -425,6 +425,7 @@ int mysql_update(THD *thd, ...@@ -425,6 +425,7 @@ int mysql_update(THD *thd,
{ {
goto err; goto err;
} }
thd->examined_row_count+= examined_rows;
/* /*
Filesort has already found and selected the rows we want to update, Filesort has already found and selected the rows we want to update,
so we don't need the where clause so we don't need the where clause
...@@ -471,6 +472,7 @@ int mysql_update(THD *thd, ...@@ -471,6 +472,7 @@ int mysql_update(THD *thd,
while (!(error=info.read_record(&info)) && !thd->killed) while (!(error=info.read_record(&info)) && !thd->killed)
{ {
thd->examined_row_count++;
if (!(select && select->skip_record())) if (!(select && select->skip_record()))
{ {
if (table->file->was_semi_consistent_read()) if (table->file->was_semi_consistent_read())
...@@ -577,6 +579,7 @@ int mysql_update(THD *thd, ...@@ -577,6 +579,7 @@ int mysql_update(THD *thd,
while (!(error=info.read_record(&info)) && !thd->killed) while (!(error=info.read_record(&info)) && !thd->killed)
{ {
thd->examined_row_count++;
if (!(select && select->skip_record())) if (!(select && select->skip_record()))
{ {
if (table->file->was_semi_consistent_read()) if (table->file->was_semi_consistent_read())
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment