diff --git a/mysql-test/r/log_state.result b/mysql-test/r/log_state.result index 4ce678e37aa..654f9d127d3 100644 --- a/mysql-test/r/log_state.result +++ b/mysql-test/r/log_state.result @@ -308,8 +308,41 @@ SET @@global.general_log = @old_general_log; SET @@global.general_log_file = @old_general_log_file; SET @@global.slow_query_log = @old_slow_query_log; 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 # 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_file = @old_general_log_file; SET global slow_query_log = @old_slow_query_log; diff --git a/mysql-test/t/log_state.test b/mysql-test/t/log_state.test index e40dd1e3491..05e17dc9fa7 100644 --- a/mysql-test/t/log_state.test +++ b/mysql-test/t/log_state.test @@ -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 --enable_ps_protocol @@ -376,6 +412,8 @@ disconnect con1; connection default; # 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_file = @old_general_log_file; SET global slow_query_log = @old_slow_query_log; diff --git a/sql/sql_class.h b/sql/sql_class.h index 4d0552c5b9d..bd3cf8bc401 100644 --- a/sql/sql_class.h +++ b/sql/sql_class.h @@ -1716,8 +1716,15 @@ public: */ 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; diff --git a/sql/sql_delete.cc b/sql/sql_delete.cc index 7e91a37257b..cc29b6f1b6b 100644 --- a/sql/sql_delete.cc +++ b/sql/sql_delete.cc @@ -248,6 +248,7 @@ bool mysql_delete(THD *thd, TABLE_LIST *table_list, COND *conds, free_underlaid_joins(thd, &thd->lex->select_lex); DBUG_RETURN(TRUE); } + thd->examined_row_count+= examined_rows; /* Filesort has already found and selected the rows we want to delete, so we don't need the where clause @@ -304,6 +305,7 @@ bool mysql_delete(THD *thd, TABLE_LIST *table_list, COND *conds, while (!(error=info.read_record(&info)) && !thd->killed && ! thd->is_error()) { + thd->examined_row_count++; // thd->is_error() is tested to disallow delete row on error if (!(select && select->skip_record())&& ! thd->is_error() ) { diff --git a/sql/sql_update.cc b/sql/sql_update.cc index d8141deba63..69f3a29e923 100644 --- a/sql/sql_update.cc +++ b/sql/sql_update.cc @@ -425,6 +425,7 @@ int mysql_update(THD *thd, { goto err; } + thd->examined_row_count+= examined_rows; /* Filesort has already found and selected the rows we want to update, so we don't need the where clause @@ -471,6 +472,7 @@ int mysql_update(THD *thd, while (!(error=info.read_record(&info)) && !thd->killed) { + thd->examined_row_count++; if (!(select && select->skip_record())) { if (table->file->was_semi_consistent_read()) @@ -577,6 +579,7 @@ int mysql_update(THD *thd, while (!(error=info.read_record(&info)) && !thd->killed) { + thd->examined_row_count++; if (!(select && select->skip_record())) { if (table->file->was_semi_consistent_read())