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

[Oleg Tsarev]

      * "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

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

[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.

[lp:~tsarev/percona-server/5.5_fix_bug_716210]

152. By Oleg Tsarev on 2011-10-06

extend tests

Unmerged revisions

152. By Oleg Tsarev on 2011-10-06

extend tests

151. By Oleg Tsarev on 2011-09-28

  * "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

=== modified file 'patches/slow_extended.patch'
--- patches/slow_extended.patch	2011-09-28 14:25:37 +0000
+++ patches/slow_extended.patch	2011-10-06 23:44: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;
-@@ -3656,6 +3689,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())
-@@ -3676,6 +3715,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;
- }
- 
- 
-@@ -3738,6 +3785,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(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,50 @@
 +  ulong      innodb_innodb_que_wait_timer;
 +  ulong      innodb_page_access;
 +
++  ulong      query_plan_flags;
++  ulong      query_plan_fsort_passes;
++  /*** Belowing variables and methods used in slow_extended.patch ***/
++
    SAVEPOINT *savepoints;
    enum enum_check_fields count_cuted_fields;
  };
-@@ -1588,6 +1638,26 @@
+@@ -1588,6 +1648,72 @@
    thr_lock_type update_lock_default;
    Delayed_insert *di;
  
++  /*** Following variables used in slow_extended.patch ***/
++  /*
++    Variable write_to_slow _log:
++     1) inited in
++       * sql_connect.cc (log_slow_rate_limit support)
++       * slave.cc       (log_slow_slave_statements support)
++     2) variable never changed while thread works
++       * ATTENTION: this would be changed according to:
++         Launchpad bug #712396: "log_slow_slave_statements not work
++                                 on replication threads without RESTART"
++     3) variable should be used for:
++        LP bug #688646: "Make query sampling possible by query"
++  */
 +  bool       write_to_slow_log;
-+
++  /*
++    Variable bytes_send_old save 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 show 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 +800,30 @@
 +  ulong      innodb_innodb_que_wait_timer;
 +  ulong      innodb_page_access;
 +
++  /*
++    Variable query_plan_flags collect information about query plan entites
++    used on query execution.
++  */
 +  ulong      query_plan_flags;
++  /*
++    Variable query_plan_fsort_passes collect information about file sort passes
++    acquired during query execution.
++  */
 +  ulong      query_plan_fsort_passes;
-+
++  /*
++    Query can generates several errors/warnings during execution
++    (see THD::handle_condition comment in sql_class.h)
++    Variable last_errno contain last error/warning acquired during
++    query execution.
++  */
 +  uint       last_errno;
++  /*** Belowing variables and methods 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(Sub_statement_state *backup);
++  /*** Belowing methods used in slow_extended.patch ***/
 +
    /* <> 0 if we are inside of trigger or stored function. */
    uint in_sub_stmt;
@@ -731,7 +856,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 +925,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 +975,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 @@
@@ -2425,6 +2536,7 @@
 +--let grep_pattern = Last_errno: 1050
 +--source include/log_grep.inc
 +DROP TABLE t;
+<<<<<<< TREE
 --- /dev/null
 +++ b/mysql-test/suite/sys_vars/t/log_slow_admin_statements_basic.test
 @@ -0,0 +1 @@
@@ -2574,3 +2686,322 @@
 @@ -0,0 +1,2 @@
 +SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
 +SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
+=======
+--- /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 ################################################################################
+>>>>>>> MERGE-SOURCE