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.



sql/sql_class.h:
  Added more docs for THD::examined_row_count.
sql/sql_delete.cc:
  Add incrementing thd->examined_row_count.
sql/sql_update.cc:
  Add incrementing thd->examined_row_count.

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;

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;

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;
 

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() )
     {

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())