Merge lp:~tsarev/percona-server/5.5_fix_bug_716210_3 into lp:percona-server/5.5

[Oleg Tsarev]

From previous version of MP: I added additional tests (Rows_{read|affected|examined|sent}, Tmp_{tables|disk_tables|table_sizes], Bytes_sent, InnoDB statistics).

Applied Laurynas's recomendations. I can't do method "reset_sub_statement_slow_extended(Sub_statement_state *backup") const, because reset_sub_statement_slow_extended clear members of THD (call clear_slow_extended method).
But I add const to argument of "restore_sub_statement_slow_extended(const Sub_statement *backup)"
Laurynas, thank you for your review and attention to details.

Clean Jenkins results: http://jenkins.percona.com/view/Percona%20Server%205.5/job/percona-server-5.5-param/165

Origianl description:
      * "all statistics variables used in slow_extended.patch and thd->send_row_count and thd->examined_row_count" == SESV (Slow Extended Statistic Variables)

      * Added to class THD (sql/sql_class.h) following methods:
             1) clear_slow_extended - clear SESV
             2) reset_sub_statement_state_slow_extended(Sub_statement_state *backup) - backup SESV to backup area
             3) restore_sub_statement_state_slow_extended(Sub_statement_state *backup) - restore SESV from backup area

      * Added to class Sub_statement_state (sql/sql_class.h) required for correct backup variables

      * Added to class THD (sql/sql_class.h) comments near the SESV with explanations of purpose of variables

      * Added call of clear_slow_extended to THD::init() (required on THD class initialisation and change_user)

      * Fix admin command processing in LOGGER::slow_log_print (sql/loc.cc). Before fix SESV don't clean correctly (because if(!query_length) never was true).
        Explanation:
          1) query and query_length according to comment in sql_class.h always correlated - if query == NULL => query_length == 0, and if query != NULL => query_length != 0
          2) After "if (!query) { ... }" query_lenght always not 0
          3) if (!query_length) (code before my fix) always trye

      * Fixed accoring to code policy code formating in "increment_thd_innodb_stats" (sql/sql_class.cc)

      * Fixed THD::reset_for_next_command (sql/sql_parse.cc) - replace variables cleaning by clear_slow_extended call

      * Fixed bug #716210: add thd->clear_slow_extended() to dispatch_command()
        Explanation: before dispatch_command mysql doesn't call "reset_for_next_command" and SESV inherited from previous query

[Oleg Tsarev (tsarev)]

http://jenkins.percona.com/view/Percona%20Server%205.1/job/percona-server-5.1-param/133/

[Oleg Tsarev (tsarev)]

http://jenkins.percona.com/view/Percona%20Server%205.1/job/percona-server-5.1-param/138

[Laurynas Biveinis (laurynas-biveinis)]

LGTM provided that Jenkins result are clean

review: Approve

[Alexey Kopytov (akopytov)]

last_errno is not the only variable that has to be reset for admin commands after a failing statement. Most other counters from slow_extended are affected by the same problem.

Here's an test case:

create table t1(a int primary key);
insert into t1 values (1), (2), (3);
insert into t1 select * from t1 order by rand();

The last statement will fail ER_DUP_ENTRY, and the next admin command will have the same Last_errno, Rows_{sent,examined,affected,read}, Bytes_sent, Tmp_tables, Tmp_disk_tables and Tmp_table_sizes.

I'm fairly sure InnoDB stats have the same problem.

Some comments on the test case:

- with use_global_long_query_time=1 do you really need to create a separate connection?
- please replace 1050 with ER_TABLE_EXISTS_ERROR.

review: Needs Fixing

[Laurynas Biveinis (laurynas-biveinis)]

- I am not sure the class Sub_statement_state is the best place to piggyback the backup info too (maybe Alexey can comment on this.) Perhaps a separate struct is needed?
- Please extend the testcase to show that other variables (Rows_{sent,examined,affected,read}, Bytes_sent, Tmp_tables, Tmp_disk_tables and Tmp_table_sizes) are reset correctly, as pointed out by Alexey.

Typos in the comment at 282--294:
1) "write_to_slow _log"
2) s/inited/initialized
3) I'm not sure what "2)" and "3)" in the comment are trying to say.

Lines 313: I'm not sure what "Following Variables innodb_*** (is |should be) different from" is supposed to mean
Lines 324,329: s/collect/collects
Line 335: s/generates/generate
Line 337: s/contain/contains the
Line 346: constify the argument (unless something prevents this)

review: Needs Fixing

[Oleg Tsarev (tsarev)]

> - I am not sure the class Sub_statement_state is the best place to piggyback
> the backup info too (maybe Alexey can comment on this.) Perhaps a separate
> struct is needed?

You can look intо:
void THD::reset_sub_statement_state(Sub_statement_state *backup);

This method use Sub_statement_state for backup all required variables.
I just extend it by me variables (as this was in first version of patch).

Of course, I can extract structure to separated Sub_statement_state_slow_extended, but this is overenginnering, no?

> - Please extend the testcase to show that other variables
> (Rows_{sent,examined,affected,read}, Bytes_sent, Tmp_tables, Tmp_disk_tables
> and Tmp_table_sizes) are reset correctly, as pointed out by Alexey.

ACK

>
> Typos in the comment at 282--294:
> 1) "write_to_slow _log"
> 2) s/inited/initialized
> 3) I'm not sure what "2)" and "3)" in the comment are trying to say.

2) and 3) about variable "write_to_slow_log":
  2) write_to_slow_log never changed (changed just on thread start time)
  3) write_to_slow_log should be used in implementation of feature "sampling by query"

>
> Lines 313: I'm not sure what "Following Variables innodb_*** (is |should be)
> different from" is supposed to mean
> Lines 324,329: s/collect/collects
> Line 335: s/generates/generate
> Line 337: s/contain/contains the
> Line 346: constify the argument (unless something prevents this)

[Laurynas Biveinis (laurynas-biveinis)]

> This method use Sub_statement_state for backup all required variables.
> I just extend it by me variables (as this was in first version of patch).
>
> Of course, I can extract structure to separated
> Sub_statement_state_slow_extended, but this is overenginnering, no?

I have looked more carefully, and I see that some of the already-existing Sub_statement_state fields are used for backup too. Now I agree that just extending it is OK.

> > 3) I'm not sure what "2)" and "3)" in the comment are trying to say.
>
> 2) and 3) about variable "write_to_slow_log":
> 2) write_to_slow_log never changed (changed just on thread start time)
> 3) write_to_slow_log should be used in implementation of feature "sampling
> by query"

2) The variable is initialized on the thread startup and remains constant afterwards. This will change when LP #712396 ("log_slow_slave_statements not work on replication threads without RESTART") is implemented.
3) An implementation of LP #688646 ("Make query sampling possible by query") should use it.

[Laurynas Biveinis (laurynas-biveinis)]

LGTM with the the first comment below replied to and the rest of the changes. As far as I'm concerned, if the adjusted patch will be different from the current one with the changes below and nothing else, a new MP is not necessary.

- Can the argument of
  THD::restore_sub_statement_state_slow_extended(Sub_statement_state
  *backup) and the method void
  THD::reset_sub_statement_state_slow_extended(Sub_statement_state
  *backup) be constified?

- Line 294: s/save/saves

- Line 305: s/innodb_was used show/innodb_was_used shows

- Line 272: s/Belowing/Following

- Line 288: please wrap at 78th column

- Line 337: s/Belowing/Following or remove altogether (line 339 almost duplicate)

review: Approve

[Laurynas Biveinis (laurynas-biveinis)]

LGTM

review: Approve

=== modified file 'patches/slow_extended.patch'
--- patches/slow_extended.patch	2011-10-11 20:41:24 +0000
+++ patches/slow_extended.patch	2011-10-11 20:41:24 +0000
@@ -227,29 +227,16 @@
      }
      else
      {
-@@ -1239,8 +1255,20 @@
-       query_length= command_name[thd->command].length;
+@@ -1240,7 +1256,7 @@
      }
  
-+    if (!query_length)
-+    {
-+      thd->sent_row_count= thd->examined_row_count= 0;
-+      thd->sent_row_count= 0;
-+      thd->bytes_sent_old= thd->status_var.bytes_sent;
-+      thd->tmp_tables_used= thd->tmp_tables_disk_used= 0;
-+      thd->tmp_tables_size= 0;
-+      thd->innodb_was_used= FALSE;
-+      thd->query_plan_flags= QPLAN_NONE;
-+      thd->query_plan_fsort_passes= 0;
-+    }
-+
      for (current_handler= slow_log_handler_list; *current_handler ;)
 -      error= (*current_handler++)->log_slow(thd, current_time, thd->start_time,
 +      error= (*current_handler++)->log_slow(thd, current_utime, thd->start_time,
                                              user_host_buff, user_host_len,
                                              query_utime, lock_utime, is_command,
                                              query, query_length) || error;
-@@ -2656,12 +2684,13 @@
+@@ -2656,12 +2672,13 @@
      TRUE - error occured
  */
  
@@ -264,7 +251,7 @@
    bool error= 0;
    DBUG_ENTER("MYSQL_QUERY_LOG::write");
  
-@@ -2683,17 +2712,28 @@
+@@ -2683,17 +2700,28 @@
  
      if (!(specialflag & SPECIAL_SHORT_LOG_FORMAT))
      {
@@ -300,9 +287,11 @@
  
          /* Note that my_b_write() assumes it knows the length for this */
          if (my_b_write(&log_file, (uchar*) buff, buff_len))
-@@ -2711,12 +2751,69 @@
+@@ -2710,13 +2738,71 @@
+     /* For slow query log */
      sprintf(query_time_buff, "%.6f", ulonglong2double(query_utime)/1000000.0);
      sprintf(lock_time_buff,  "%.6f", ulonglong2double(lock_utime)/1000000.0);
++    DBUG_PRINT("info", ("Last_errno: %u", thd->last_errno));
      if (my_b_printf(&log_file,
 -                    "# Query_time: %s  Lock_time: %s"
 -                    " Rows_sent: %lu  Rows_examined: %lu\n",
@@ -521,22 +510,22 @@
  
 +extern "C"
 +void increment_thd_innodb_stats(THD* thd,
-+                    unsigned long long trx_id,
-+                    long io_reads,
-+                    long long  io_read,
-+                    long      io_reads_wait_timer,
-+                    long      lock_que_wait_timer,
-+                    long      que_wait_timer,
-+                    long      page_access)
++                                unsigned long long trx_id,
++                                long io_reads,
++                                long long  io_read,
++                                long      io_reads_wait_timer,
++                                long      lock_que_wait_timer,
++                                long      que_wait_timer,
++                                long      page_access)
 +{
-+  thd->innodb_was_used = TRUE;
-+  thd->innodb_trx_id = trx_id;
-+  thd->innodb_io_reads += io_reads;
-+  thd->innodb_io_read += io_read;
-+  thd->innodb_io_reads_wait_timer += io_reads_wait_timer;
-+  thd->innodb_lock_que_wait_timer += lock_que_wait_timer;
-+  thd->innodb_innodb_que_wait_timer += que_wait_timer;
-+  thd->innodb_page_access += page_access;
++  thd->innodb_was_used=               TRUE;
++  thd->innodb_trx_id=                 trx_id;
++  thd->innodb_io_reads+=              io_reads;
++  thd->innodb_io_read+=               io_read;
++  thd->innodb_io_reads_wait_timer+=   io_reads_wait_timer;
++  thd->innodb_lock_que_wait_timer+=   lock_que_wait_timer;
++  thd->innodb_innodb_que_wait_timer+= que_wait_timer;
++  thd->innodb_page_access+=           page_access;
 +}
 +
 +extern "C"
@@ -562,44 +551,124 @@
    if (!m_internal_handler)
    {
      *cond_hdl= NULL;
-@@ -3675,6 +3708,12 @@
+@@ -1201,6 +1234,8 @@
+   /* Initialize the Debug Sync Facility. See debug_sync.cc. */
+   debug_sync_init_thread(this);
+ #endif /* defined(ENABLED_DEBUG_SYNC) */
++
++  clear_slow_extended();
+ }
+ 
+ 
+@@ -3647,8 +3682,6 @@
+   backup->in_sub_stmt=     in_sub_stmt;
+   backup->enable_slow_log= enable_slow_log;
+   backup->limit_found_rows= limit_found_rows;
+-  backup->examined_row_count= examined_row_count;
+-  backup->sent_row_count=   sent_row_count;
+   backup->cuted_fields=     cuted_fields;
+   backup->client_capabilities= client_capabilities;
+   backup->savepoints= transaction.savepoints;
+@@ -3656,6 +3689,7 @@
      first_successful_insert_id_in_prev_stmt;
    backup->first_successful_insert_id_in_cur_stmt= 
      first_successful_insert_id_in_cur_stmt;
-+  backup->innodb_io_reads= innodb_io_reads;
-+  backup->innodb_io_read= innodb_io_read;
-+  backup->innodb_io_reads_wait_timer= innodb_io_reads_wait_timer;
-+  backup->innodb_lock_que_wait_timer= innodb_lock_que_wait_timer;
-+  backup->innodb_innodb_que_wait_timer= innodb_innodb_que_wait_timer;
-+  backup->innodb_page_access= innodb_page_access;
++  reset_sub_statement_state_slow_extended(backup);
  
    if ((!lex->requires_prelocking() || is_update_query(lex->sql_command)) &&
        !is_current_stmt_binlog_format_row())
-@@ -3695,6 +3734,14 @@
+@@ -3671,13 +3705,74 @@
+   /* Disable result sets */
+   client_capabilities &= ~CLIENT_MULTI_RESULTS;
+   in_sub_stmt|= new_state;
+-  examined_row_count= 0;
+-  sent_row_count= 0;
    cuted_fields= 0;
    transaction.savepoints= 0;
    first_successful_insert_id_in_cur_stmt= 0;
-+  last_errno= 0;
-+  innodb_trx_id= 0;
-+  innodb_io_reads= 0;
-+  innodb_io_read= 0;
-+  innodb_io_reads_wait_timer= 0;
-+  innodb_lock_que_wait_timer= 0;
+ }
+ 
++void THD::clear_slow_extended()
++{
++  DBUG_ENTER("THD::clear_slow_extended");
++  sent_row_count=               0;
++  examined_row_count=           0;
++  bytes_sent_old=               status_var.bytes_sent;
++  tmp_tables_used=              0;
++  tmp_tables_disk_used=         0;
++  tmp_tables_size=              0;
++  innodb_was_used=              FALSE;
++  innodb_trx_id=                0;
++  innodb_io_reads=              0;
++  innodb_io_read=               0;
++  innodb_io_reads_wait_timer=   0;
++  innodb_lock_que_wait_timer=   0;
 +  innodb_innodb_que_wait_timer= 0;
-+  innodb_page_access= 0;
- }
- 
- 
-@@ -3757,6 +3804,12 @@
++  innodb_page_access=           0;
++  query_plan_flags=             QPLAN_NONE;
++  query_plan_fsort_passes=      0;
++  last_errno=                   0;
++  DBUG_VOID_RETURN;
++}
++
++void THD::reset_sub_statement_state_slow_extended(Sub_statement_state *backup)
++{
++  DBUG_ENTER("THD::reset_sub_statement_state_slow_extended");
++  backup->sent_row_count=               sent_row_count;
++  backup->examined_row_count=           examined_row_count;
++  backup->tmp_tables_used=              tmp_tables_used;
++  backup->tmp_tables_disk_used=         tmp_tables_disk_used;
++  backup->tmp_tables_size=              tmp_tables_size;
++  backup->innodb_was_used=              innodb_was_used;
++  backup->innodb_io_reads=              innodb_io_reads;
++  backup->innodb_io_read=               innodb_io_read;
++  backup->innodb_io_reads_wait_timer=   innodb_io_reads_wait_timer;
++  backup->innodb_lock_que_wait_timer=   innodb_lock_que_wait_timer;
++  backup->innodb_innodb_que_wait_timer= innodb_innodb_que_wait_timer;
++  backup->innodb_page_access=           innodb_page_access;
++  backup->query_plan_flags=             query_plan_flags;
++  backup->query_plan_fsort_passes=      query_plan_fsort_passes;
++  clear_slow_extended();
++  DBUG_VOID_RETURN;
++}
++
++void THD::restore_sub_statement_state_slow_extended(const Sub_statement_state *backup)
++{
++  DBUG_ENTER("THD::restore_sub_statement_state_slow_extended");
++  sent_row_count=                backup->sent_row_count;
++  examined_row_count+=           backup->examined_row_count;
++  tmp_tables_used+=              backup->tmp_tables_used;
++  tmp_tables_disk_used+=         backup->tmp_tables_disk_used;
++  tmp_tables_size+=              backup->tmp_tables_size;
++  innodb_was_used=               (innodb_was_used || backup->innodb_was_used);
++  innodb_io_reads+=              backup->innodb_io_reads;
++  innodb_io_read+=               backup->innodb_io_read;
++  innodb_io_reads_wait_timer+=   backup->innodb_io_reads_wait_timer;
++  innodb_lock_que_wait_timer+=   backup->innodb_lock_que_wait_timer;
++  innodb_innodb_que_wait_timer+= backup->innodb_innodb_que_wait_timer;
++  innodb_page_access+=           backup->innodb_page_access;
++  query_plan_flags|=             backup->query_plan_flags;
++  query_plan_fsort_passes+=      backup->query_plan_fsort_passes;
++  DBUG_VOID_RETURN;
++}
+ 
+ void THD::restore_sub_statement_state(Sub_statement_state *backup)
+ {
+@@ -3718,7 +3813,6 @@
+   first_successful_insert_id_in_cur_stmt= 
+     backup->first_successful_insert_id_in_cur_stmt;
+   limit_found_rows= backup->limit_found_rows;
+-  sent_row_count=   backup->sent_row_count;
+   client_capabilities= backup->client_capabilities;
+   /*
+     If we've left sub-statement mode, reset the fatal error flag.
+@@ -3736,8 +3830,8 @@
+     The following is added to the old values as we are interested in the
+     total complexity of the query
    */
-   examined_row_count+= backup->examined_row_count;
+-  examined_row_count+= backup->examined_row_count;
    cuted_fields+=       backup->cuted_fields;
-+  innodb_io_reads+= backup->innodb_io_reads;
-+  innodb_io_read+= backup->innodb_io_read;
-+  innodb_io_reads_wait_timer+= backup->innodb_io_reads_wait_timer;
-+  innodb_lock_que_wait_timer+= backup->innodb_lock_que_wait_timer;
-+  innodb_innodb_que_wait_timer+= backup->innodb_innodb_que_wait_timer;
-+  innodb_page_access+= backup->innodb_page_access;
++  restore_sub_statement_state_slow_extended(backup);
    DBUG_VOID_RETURN;
  }
  
@@ -661,11 +730,17 @@
    double long_query_time_double;
  
  } SV;
-@@ -1140,6 +1182,14 @@
+@@ -1140,6 +1182,24 @@
    uint in_sub_stmt;
    bool enable_slow_log;
    bool last_insert_id_used;
 +
++  /*** Following variables used in slow_extended.patch ***/
++  ulong      tmp_tables_used;
++  ulong      tmp_tables_disk_used;
++  ulonglong  tmp_tables_size;
++
++  bool       innodb_was_used;
 +  ulong      innodb_io_reads;
 +  ulonglong  innodb_io_read;
 +  ulong      innodb_io_reads_wait_timer;
@@ -673,20 +748,49 @@
 +  ulong      innodb_innodb_que_wait_timer;
 +  ulong      innodb_page_access;
 +
++  ulong      query_plan_flags;
++  ulong      query_plan_fsort_passes;
++  /*** The variables above used in slow_extended.patch ***/
++
    SAVEPOINT *savepoints;
    enum enum_check_fields count_cuted_fields;
  };
-@@ -1588,6 +1638,26 @@
+@@ -1588,6 +1648,71 @@
    thr_lock_type update_lock_default;
    Delayed_insert *di;
  
++  /*** Following variables used in slow_extended.patch ***/
++  /*
++    Variable write_to_slow_log:
++     1) initialized in
++       * sql_connect.cc (log_slow_rate_limit support)
++       * slave.cc       (log_slow_slave_statements support)
++     2) The variable is initialized on the thread startup and remains
++        constant afterwards.  This will change when 
++        LP #712396 ("log_slow_slave_statements not work on replication 
++        threads without RESTART") is implemented.
++     3) An implementation of LP #688646 ("Make query sampling possible by query") should use it.
++  */
 +  bool       write_to_slow_log;
-+
++  /*
++    Variable bytes_send_old saves value of thd->status_var.bytes_sent
++    before query execution.
++  */
 +  ulonglong  bytes_sent_old;
++  /*
++    Variables tmp_tables_*** collect statistics about usage of temporary tables
++  */
 +  ulong      tmp_tables_used;
 +  ulong      tmp_tables_disk_used;
 +  ulonglong  tmp_tables_size;
++  /*
++    Variable innodb_was_used shows used or not InnoDB engine in current query.
++  */
 +  bool       innodb_was_used;
++  /*
++    Following Variables innodb_*** (is |should be) different from
++    default values only if (innodb_was_used==TRUE)
++  */
 +  ulonglong  innodb_trx_id;
 +  ulong      innodb_io_reads;
 +  ulonglong  innodb_io_read;
@@ -695,10 +799,30 @@
 +  ulong      innodb_innodb_que_wait_timer;
 +  ulong      innodb_page_access;
 +
++  /*
++    Variable query_plan_flags collects information about query plan entites
++    used on query execution.
++  */
 +  ulong      query_plan_flags;
++  /*
++    Variable query_plan_fsort_passes collects information about file sort passes
++    acquired during query execution.
++  */
 +  ulong      query_plan_fsort_passes;
-+
++  /*
++    Query can generate several errors/warnings during execution
++    (see THD::handle_condition comment in sql_class.h)
++    Variable last_errno contains the last error/warning acquired during
++    query execution.
++  */
 +  uint       last_errno;
++  /*** The variables above used in slow_extended.patch ***/
++
++  /*** Following methods used in slow_extended.patch ***/
++  void clear_slow_extended();
++  void reset_sub_statement_state_slow_extended(Sub_statement_state *backup);
++  void restore_sub_statement_state_slow_extended(const Sub_statement_state *backup);
++  /*** The methods above used in slow_extended.patch ***/
 +
    /* <> 0 if we are inside of trigger or stored function. */
    uint in_sub_stmt;
@@ -731,7 +855,15 @@
  
  const char *any_db="*any*";	// Special symbol for check_access
  
-@@ -1430,6 +1431,60 @@
+@@ -888,6 +889,7 @@
+     the slow log only if opt_log_slow_admin_statements is set.
+   */
+   thd->enable_slow_log= TRUE;
++  thd->clear_slow_extended();
+   thd->lex->sql_command= SQLCOM_END; /* to avoid confusing VIEW detectors */
+   thd->set_time();
+   if (!thd->is_valid_time())
+@@ -1430,6 +1432,60 @@
    DBUG_RETURN(error);
  }
  
@@ -792,7 +924,7 @@
  
  void log_slow_statement(THD *thd)
  {
-@@ -1443,13 +1498,48 @@
+@@ -1443,13 +1499,48 @@
    if (unlikely(thd->in_sub_stmt))
      DBUG_VOID_RETURN;                           // Don't set time for sub stmt
  
@@ -842,38 +974,16 @@
      thd_proc_info(thd, "logging slow query");
  
      if (((thd->server_status & SERVER_QUERY_WAS_SLOW) ||
-@@ -1879,6 +1969,9 @@
-     context.resolve_in_table_list_only(select_lex->
-                                        table_list.first);
- 
-+  /* Reset the counter at all cases for the extended slow query log */
-+  thd->sent_row_count= 0;
-+
-   /*
-     Reset warning count for each query that uses tables
-     A better approach would be to reset this for any commands
-@@ -5297,6 +5390,21 @@
+@@ -5295,7 +5386,8 @@
+   thd->stmt_da->reset_diagnostics_area();
+   thd->warning_info->reset_for_next_command();
    thd->rand_used= 0;
-   thd->sent_row_count= thd->examined_row_count= 0;
+-  thd->sent_row_count= thd->examined_row_count= 0;
++
++  thd->clear_slow_extended();
  
-+  thd->bytes_sent_old= thd->status_var.bytes_sent;
-+  thd->tmp_tables_used= thd->tmp_tables_disk_used= 0;
-+  thd->tmp_tables_size= 0;
-+  thd->innodb_was_used= FALSE;
-+  thd->innodb_trx_id= 0;
-+  thd->innodb_io_reads= 0;
-+  thd->innodb_io_read= 0;
-+  thd->innodb_io_reads_wait_timer= 0;
-+  thd->innodb_lock_que_wait_timer= 0;
-+  thd->innodb_innodb_que_wait_timer= 0;
-+  thd->innodb_page_access= 0;
-+  thd->query_plan_flags= QPLAN_NONE;
-+  thd->query_plan_fsort_passes= 0;
-+  thd->last_errno= 0;
-+
    thd->reset_current_stmt_binlog_format_row();
    thd->binlog_unsafe_warning_flags= 0;
- 
 --- a/sql/sql_select.cc
 +++ b/sql/sql_select.cc
 @@ -6902,7 +6902,10 @@
@@ -2651,3 +2761,320 @@
  sort-buffer-size 2097152
  sporadic-binlog-dump-fail FALSE
  sql-mode 
+--- /dev/null
++++ b/mysql-test/t/percona_slow_extended_error_on_quit.test
+@@ -0,0 +1,87 @@
++################################################################################
++# Current test check following attributes:                                     #
++# 1) "Last_errno"                                                              #
++# 2) "Rows_{sent,examined|affected|read}                                       #
++# 3) Bytes_sent                                                                #
++# 4) Tmp_{tables|dist_tables|table_size}                                       #
++# 5) InnoDB statistic counters                                                 #
++# in Slow Query Log                                                            #
++# for administrative command "Quit"                                            #
++#                                                                              #
++# See Launchpad Bug #716210                                                    #
++################################################################################
++
++--source include/have_innodb.inc
++
++################################################################################
++--let log_file=percona.slow_extended.error_on_quit
++--let wait_condition=SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST;
++################################################################################
++
++--disable_warnings
++DROP TABLE IF EXISTS t;
++--enable_warnings
++CREATE TABLE t(a INT) engine=InnoDB;
++INSERT INTO t VALUES(0),(1),(2),(3),(4);
++
++################################################################################
++--source include/log_start.inc
++
++--connect(additional,localhost,root,,)
++--connection additional
++
++  SET log_slow_verbosity=innodb;
++  SET long_query_time= 0;
++
++--disable_result_log
++--error ER_TABLE_EXISTS_ERROR
++  CREATE TABLE t(a INT) engine=InnoDB;
++--enable_result_log
++
++--connection default
++--echo # Disconnecting (passing to Slow Query Log "# administrative command: Quit")
++--disconnect additional
++--source include/wait_condition.inc
++--source include/log_stop.inc
++--source include/percona_slow_extended_error_on_quit.inc
++################################################################################
++--source include/log_start.inc
++
++--connect(additional,localhost,root,,)
++--connection additional
++
++  SET log_slow_verbosity=innodb;
++  SET long_query_time= 0;
++
++--disable_result_log
++  INSERT INTO t SELECT * FROM t ORDER BY RAND();
++--enable_result_log
++
++--connection default
++--echo # Disconnecting (passing to Slow Query Log "# administrative command: Quit")
++--disconnect additional
++--source include/wait_condition.inc
++--source include/log_stop.inc
++--source include/percona_slow_extended_error_on_quit.inc
++################################################################################
++--source include/log_start.inc
++
++--connect(additional,localhost,root,,)
++--connection additional
++
++  SET log_slow_verbosity=innodb;
++  SET long_query_time= 0;
++
++--disable_result_log
++  SELECT * FROM t;
++--enable_result_log
++
++--connection default
++--echo # Disconnecting (passing to Slow Query Log "# administrative command: Quit")
++--disconnect additional
++--source include/wait_condition.inc
++--source include/log_stop.inc
++--source include/percona_slow_extended_error_on_quit.inc
++################################################################################
++
++DROP TABLE t;
+--- /dev/null
++++ b/mysql-test/r/percona_slow_extended_error_on_quit.result
+@@ -0,0 +1,171 @@
++DROP TABLE IF EXISTS t;
++CREATE TABLE t(a INT) engine=InnoDB;
++INSERT INTO t VALUES(0),(1),(2),(3),(4);
++[log_start.inc] percona.slow_extended.error_on_quit
++SET log_slow_verbosity=innodb;
++SET long_query_time= 0;
++CREATE TABLE t(a INT) engine=InnoDB;
++# Disconnecting (passing to Slow Query Log "# administrative command: Quit")
++[log_stop.inc] percona.slow_extended.error_on_quit
++################################################################################
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: CREATE
++[log_grep.inc] lines:   1
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: INSERT
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: SELECT
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Quit
++[log_grep.inc] lines:   1
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Last_errno: [^0]+
++[log_grep.inc] lines:   1
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Last_errno: 0
++[log_grep.inc] lines:   2
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_sent: [^0]+
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_sent: 0
++[log_grep.inc] lines:   3
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_examined: [^0]+
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_examined: 0
++[log_grep.inc] lines:   3
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_affected: [^0]+
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_affected: 0
++[log_grep.inc] lines:   3
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_read: [^0]+
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_read: 0
++[log_grep.inc] lines:   3
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Bytes_sent: [^0]+
++[log_grep.inc] lines:   2
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Bytes_sent: 0
++[log_grep.inc] lines:   1
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_tables: [^0]+
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_tables: 0
++[log_grep.inc] lines:   3
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_disk_tables: [^0]+
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_disk_tables: 0
++[log_grep.inc] lines:   3
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_table_sizes: [^0]+
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_table_sizes: 0
++[log_grep.inc] lines:   3
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: # No InnoDB statistics available for this query
++[log_grep.inc] lines:   2
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: # InnoDB_trx_id: 
++[log_grep.inc] lines:   1
++################################################################################
++[log_start.inc] percona.slow_extended.error_on_quit
++SET log_slow_verbosity=innodb;
++SET long_query_time= 0;
++INSERT INTO t SELECT * FROM t ORDER BY RAND();
++# Disconnecting (passing to Slow Query Log "# administrative command: Quit")
++[log_stop.inc] percona.slow_extended.error_on_quit
++################################################################################
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: CREATE
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: INSERT
++[log_grep.inc] lines:   1
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: SELECT
++[log_grep.inc] lines:   1
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Quit
++[log_grep.inc] lines:   1
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Last_errno: [^0]+
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Last_errno: 0
++[log_grep.inc] lines:   3
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_sent: [^0]+
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_sent: 0
++[log_grep.inc] lines:   3
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_examined: [^0]+
++[log_grep.inc] lines:   1
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_examined: 0
++[log_grep.inc] lines:   2
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_affected: [^0]+
++[log_grep.inc] lines:   2
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_affected: 0
++[log_grep.inc] lines:   1
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_read: [^0]+
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_read: 0
++[log_grep.inc] lines:   3
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Bytes_sent: [^0]+
++[log_grep.inc] lines:   2
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Bytes_sent: 0
++[log_grep.inc] lines:   1
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_tables: [^0]+
++[log_grep.inc] lines:   1
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_tables: 0
++[log_grep.inc] lines:   2
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_disk_tables: [^0]+
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_disk_tables: 0
++[log_grep.inc] lines:   3
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_table_sizes: [^0]+
++[log_grep.inc] lines:   1
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_table_sizes: 0
++[log_grep.inc] lines:   2
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: # No InnoDB statistics available for this query
++[log_grep.inc] lines:   2
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: # InnoDB_trx_id: 
++[log_grep.inc] lines:   1
++################################################################################
++[log_start.inc] percona.slow_extended.error_on_quit
++SET log_slow_verbosity=innodb;
++SET long_query_time= 0;
++SELECT * FROM t;
++# Disconnecting (passing to Slow Query Log "# administrative command: Quit")
++[log_stop.inc] percona.slow_extended.error_on_quit
++################################################################################
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: CREATE
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: INSERT
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: SELECT
++[log_grep.inc] lines:   1
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Quit
++[log_grep.inc] lines:   1
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Last_errno: [^0]+
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Last_errno: 0
++[log_grep.inc] lines:   3
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_sent: [^0]+
++[log_grep.inc] lines:   1
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_sent: 0
++[log_grep.inc] lines:   2
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_examined: [^0]+
++[log_grep.inc] lines:   1
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_examined: 0
++[log_grep.inc] lines:   2
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_affected: [^0]+
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_affected: 0
++[log_grep.inc] lines:   3
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_read: [^0]+
++[log_grep.inc] lines:   1
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_read: 0
++[log_grep.inc] lines:   2
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Bytes_sent: [^0]+
++[log_grep.inc] lines:   2
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Bytes_sent: 0
++[log_grep.inc] lines:   1
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_tables: [^0]+
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_tables: 0
++[log_grep.inc] lines:   3
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_disk_tables: [^0]+
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_disk_tables: 0
++[log_grep.inc] lines:   3
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_table_sizes: [^0]+
++[log_grep.inc] lines:   0
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_table_sizes: 0
++[log_grep.inc] lines:   3
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: # No InnoDB statistics available for this query
++[log_grep.inc] lines:   2
++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: # InnoDB_trx_id: 
++[log_grep.inc] lines:   1
++################################################################################
+--- /dev/null
++++ b/mysql-test/include/percona_slow_extended_error_on_quit.inc
+@@ -0,0 +1,50 @@
++--echo ################################################################################
++--let grep_pattern=CREATE
++--source include/log_grep.inc
++--let grep_pattern=INSERT
++--source include/log_grep.inc
++--let grep_pattern=SELECT
++--source include/log_grep.inc
++--let grep_pattern=Quit
++--source include/log_grep.inc
++--let grep_pattern=Last_errno: [^0]+
++--source include/log_grep.inc
++--let grep_pattern=Last_errno: 0
++--source include/log_grep.inc
++--let grep_pattern=Rows_sent: [^0]+
++--source include/log_grep.inc
++--let grep_pattern=Rows_sent: 0
++--source include/log_grep.inc
++--let grep_pattern=Rows_examined: [^0]+
++--source include/log_grep.inc
++--let grep_pattern=Rows_examined: 0
++--source include/log_grep.inc
++--let grep_pattern=Rows_affected: [^0]+
++--source include/log_grep.inc
++--let grep_pattern=Rows_affected: 0
++--source include/log_grep.inc
++--let grep_pattern=Rows_read: [^0]+
++--source include/log_grep.inc
++--let grep_pattern=Rows_read: 0
++--source include/log_grep.inc
++--let grep_pattern=Bytes_sent: [^0]+
++--source include/log_grep.inc
++--let grep_pattern=Bytes_sent: 0
++--source include/log_grep.inc
++--let grep_pattern=Tmp_tables: [^0]+
++--source include/log_grep.inc
++--let grep_pattern=Tmp_tables: 0
++--source include/log_grep.inc
++--let grep_pattern=Tmp_disk_tables: [^0]+
++--source include/log_grep.inc
++--let grep_pattern=Tmp_disk_tables: 0
++--source include/log_grep.inc
++--let grep_pattern=Tmp_table_sizes: [^0]+
++--source include/log_grep.inc
++--let grep_pattern=Tmp_table_sizes: 0
++--source include/log_grep.inc
++--let grep_pattern=# No InnoDB statistics available for this query
++--source include/log_grep.inc
++--let grep_pattern=# InnoDB_trx_id: 
++--source include/log_grep.inc
++--echo ################################################################################