MDEV-7899: 10.1 is 3% slower than 10.0 in OLTP RO

- Remove ANALYZE's timing code off the the execution path of regular
  SELECTs.
- Improve the tracker that tracks counts/execution times of SELECTs or
  DML statements:
  = regular execution just increments counters
  = ANALYZE will also collect timings.

sql/handler.h

@@ -4210,12 +4210,13 @@ inline const char *table_case_name(HA_CREATE_INFO *info, const char *name)
 
 #define TABLE_IO_WAIT(TRACKER, PSI, OP, INDEX, FLAGS, PAYLOAD) \
   { \
-    if (unlikely(tracker)) \
+    Exec_time_tracker *this_tracker; \
+    if (unlikely((this_tracker= tracker))) \
       tracker->start_tracking(); \
     \
     MYSQL_TABLE_IO_WAIT(PSI, OP, INDEX, FLAGS, PAYLOAD); \
     \
-    if (unlikely(tracker)) \
+    if (unlikely(this_tracker)) \
       tracker->stop_tracking(); \
   }
 

sql/sql_analyze_stmt.h

@@ -20,6 +20,7 @@
 */
 class Exec_time_tracker
 {
+protected:
   ulonglong count;
   ulonglong cycles;
   ulonglong last_start;
@@ -34,9 +35,8 @@ public:
 
   void stop_tracking()
   {
-    ulonglong last_end= my_timer_cycles();
     count++;
-    cycles += last_end - last_start;
+    cycles += my_timer_cycles()- last_start;
   }
 
   // interface for getting the time
@@ -48,3 +48,41 @@ public:
   }
 };
 
+
+/*
+  A class for counting certain actions (in all queries), and optionally
+  collecting the timings (in ANALYZE queries).
+*/
+
+class Time_and_counter_tracker: public Exec_time_tracker
+{
+public: 
+  const bool timed;
+  
+  Time_and_counter_tracker(bool timed_arg) : timed(timed_arg)
+  {}
+   
+  /* Loops are counted in both ANALYZE and regular queries, as this is cheap */
+  void incr_loops() { count++; }
+  
+  /*
+    Unlike Exec_time_tracker::stop_tracking, we don't increase loops.
+  */
+  void stop_tracking()
+  {
+    cycles += my_timer_cycles()- last_start;
+  }
+};
+
+#define ANALYZE_START_TRACKING(tracker) \
+  { \
+    (tracker)->incr_loops(); \
+    if (unlikely((tracker)->timed)) \
+    { (tracker)->start_tracking(); } \
+  }
+
+#define ANALYZE_STOP_TRACKING(tracker) \
+  if (unlikely((tracker)->timed)) \
+  { (tracker)->stop_tracking(); }
+
+

sql/sql_delete.cc

@@ -52,9 +52,11 @@
     invoked on a running DELETE statement.
 */
 
-void Delete_plan::save_explain_data(MEM_ROOT *mem_root, Explain_query *query)
+Explain_delete* Delete_plan::save_explain_delete_data(MEM_ROOT *mem_root, THD *thd)
 {
-  Explain_delete *explain= new (mem_root) Explain_delete(mem_root);
+  Explain_query *query= thd->lex->explain;
+  Explain_delete *explain= 
+     new (mem_root) Explain_delete(mem_root, thd->lex->analyze_stmt);
 
   if (deleting_all_rows)
   {
@@ -69,14 +71,19 @@ void Delete_plan::save_explain_data(MEM_ROOT *mem_root, Explain_query *query)
   }
  
   query->add_upd_del_plan(explain);
+  return explain;
 }
 
 
-void Update_plan::save_explain_data(MEM_ROOT *mem_root, Explain_query *query)
+Explain_update* 
+Update_plan::save_explain_update_data(MEM_ROOT *mem_root, THD *thd)
 {
-  Explain_update* explain= new (mem_root) Explain_update(mem_root);
+  Explain_query *query= thd->lex->explain;
+  Explain_update* explain= 
+    new (mem_root) Explain_update(mem_root, thd->lex->analyze_stmt);
   save_explain_data_intern(mem_root, query, explain);
   query->add_upd_del_plan(explain);
+  return explain;
 }
 
 
@@ -461,7 +468,8 @@ bool mysql_delete(THD *thd, TABLE_LIST *table_list, COND *conds,
   if (thd->lex->describe)
     goto produce_explain_and_leave;
   
-  query_plan.save_explain_data(thd->mem_root, thd->lex->explain);
+  explain= query_plan.save_explain_delete_data(thd->mem_root, thd);
+  ANALYZE_START_TRACKING(&explain->command_tracker);
 
   DBUG_EXECUTE_IF("show_explain_probe_delete_exec_start", 
                   dbug_serve_apcs(thd, 1););
@@ -542,7 +550,6 @@ bool mysql_delete(THD *thd, TABLE_LIST *table_list, COND *conds,
 
   explain= (Explain_delete*)thd->lex->explain->get_upd_del_plan();
   explain->tracker.on_scan_init();
-  ANALYZE_START_TRACKING(&explain->time_tracker);
 
   while (!(error=info.read_record(&info)) && !thd->killed &&
 	 ! thd->is_error())
@@ -620,7 +627,7 @@ bool mysql_delete(THD *thd, TABLE_LIST *table_list, COND *conds,
   end_read_record(&info);
   if (options & OPTION_QUICK)
     (void) table->file->extra(HA_EXTRA_NORMAL);
-  ANALYZE_STOP_TRACKING(&explain->time_tracker);
+  ANALYZE_STOP_TRACKING(&explain->command_tracker);
 
 cleanup:
   /*
@@ -701,7 +708,7 @@ produce_explain_and_leave:
     We come here for various "degenerate" query plans: impossible WHERE,
     no-partitions-used, impossible-range, etc.
   */
-  query_plan.save_explain_data(thd->mem_root, thd->lex->explain);
+  query_plan.save_explain_delete_data(thd->mem_root, thd);
 
 send_nothing_and_leave:
   /* 

sql/sql_explain.cc

@@ -1933,9 +1933,9 @@ void Explain_update::print_explain_json(Explain_query *query,
   if (using_io_buffer)
     writer->add_member("using_io_buffer").add_ll(1);
 
-  if (is_analyze && time_tracker.get_loops())
+  if (is_analyze && command_tracker.get_loops())
     writer->
-      add_member("r_total_time_ms").add_double(time_tracker.get_time_ms());
+      add_member("r_total_time_ms").add_double(command_tracker.get_time_ms());
 
   if (where_cond)
   {

sql/sql_explain.h

@@ -104,40 +104,6 @@ public:
   inline void on_record_after_where() { r_rows_after_where++; }
 };
 
-#if 0
-/*
-  A class to track operations (currently, row reads) on a PSI_table.
-*/
-class Table_op_tracker
-{
-  PSI_table *psi_table;
-
-  /* Table counter values at start. Sum is in picoseconds */
-  ulonglong start_sum;
-  ulonglong start_count;
-
-  /* Table counter values at end */
-  ulonglong end_sum;
-  ulonglong end_count;
-public:
-  void start_tracking(TABLE *table);
-  // At the moment, print_json will call end_tracking.
-  void end_tracking();
-
-  // this may print nothing if the table was not tracked.
-  void print_json(Json_writer *writer);
-};
-#endif
-
-#define ANALYZE_START_TRACKING(tracker) \
-  if (tracker) \
-  { (tracker)->start_tracking(); }
-
-#define ANALYZE_STOP_TRACKING(tracker) \
-  if (tracker) \
-  { (tracker)->stop_tracking(); }
-
-
 /**************************************************************************************
  
   Data structures for producing EXPLAIN outputs.
@@ -274,10 +240,11 @@ class Explain_select : public Explain_basic_join
 public:
   enum explain_node_type get_type() { return EXPLAIN_SELECT; }
 
-  Explain_select(MEM_ROOT *root) : 
+  Explain_select(MEM_ROOT *root, bool is_analyze) : 
   Explain_basic_join(root),
     message(NULL),
-    using_temporary(false), using_filesort(false)
+    using_temporary(false), using_filesort(false),
+    time_tracker(is_analyze)
   {}
 
   /*
@@ -303,7 +270,7 @@ public:
   bool using_filesort;
 
   /* ANALYZE members */
-  Exec_time_tracker time_tracker;
+  Time_and_counter_tracker time_tracker;
   
   int print_explain(Explain_query *query, select_result_sink *output, 
                     uint8 explain_flags, bool is_analyze);
@@ -329,7 +296,8 @@ class Explain_union : public Explain_node
 {
 public:
   Explain_union(MEM_ROOT *root) : 
-  Explain_node(root)
+  Explain_node(root),
+  time_tracker(false)
   {}
 
   enum explain_node_type get_type() { return EXPLAIN_UNION; }
@@ -364,6 +332,8 @@ public:
   const char *fake_select_type;
   bool using_filesort;
   bool using_tmp;
+  /* TODO: the below is not printed yet:*/
+  Time_and_counter_tracker time_tracker; 
 
   Table_access_tracker *get_fake_select_lex_tracker()
   {
@@ -787,8 +757,9 @@ class Explain_update : public Explain_node
 {
 public:
 
-  Explain_update(MEM_ROOT *root) : 
-  Explain_node(root)
+  Explain_update(MEM_ROOT *root, bool is_analyze) : 
+    Explain_node(root),
+    command_tracker(is_analyze)
   {}
 
   virtual enum explain_node_type get_type() { return EXPLAIN_UPDATE; }
@@ -827,7 +798,9 @@ public:
 
   /* ANALYZE members and methods */
   Table_access_tracker tracker;
-  Exec_time_tracker time_tracker;
+
+  /* This tracks execution of the whole command */
+  Time_and_counter_tracker command_tracker;
   //psergey-todo: io-tracker here.
 
   virtual int print_explain(Explain_query *query, select_result_sink *output, 
@@ -870,8 +843,8 @@ public:
 class Explain_delete: public Explain_update
 {
 public:
-  Explain_delete(MEM_ROOT *root) : 
-  Explain_update(root)
+  Explain_delete(MEM_ROOT *root, bool is_analyze) : 
+  Explain_update(root, is_analyze)
   {}
 
   /*

sql/sql_lex.cc

@@ -4374,6 +4374,12 @@ int st_select_lex_unit::save_union_explain_part2(Explain_query *output)
         eu->add_child(unit->first_select()->select_number);
       }
     }
+
+    /* 
+      Having a time tracker for reading UNION result is not very interesting
+      but is easier, as JOIN::exec now relies on having a tracker.
+    */
+    fake_select_lex->join->tracker= &eu->time_tracker;
   }
   return 0;
 }

sql/sql_lex.h

@@ -2290,6 +2290,7 @@ class SQL_SELECT;
 
 class Explain_query;
 class Explain_update;
+class Explain_delete;
 
 /* 
   Query plan of a single-table UPDATE.
@@ -2332,10 +2333,11 @@ public:
   void set_impossible_where() { impossible_where= true; }
   void set_no_partitions() { no_partitions= true; }
 
-  void save_explain_data(MEM_ROOT *mem_root, Explain_query *query);
+  Explain_update* save_explain_update_data(MEM_ROOT *mem_root, THD *thd);
+protected:
   void save_explain_data_intern(MEM_ROOT *mem_root, Explain_query *query,
                                 Explain_update *eu);
-
+public:
   virtual ~Update_plan() {}
 
   Update_plan(MEM_ROOT *mem_root_arg) : 
@@ -2365,7 +2367,7 @@ public:
     scanned_rows= rows_arg;
   }
 
-  void save_explain_data(MEM_ROOT *mem_root, Explain_query *query);
+  Explain_delete* save_explain_delete_data(MEM_ROOT *mem_root, THD *thd);
 };
 
 

sql/sql_select.cc

@@ -23441,8 +23441,11 @@ void JOIN_TAB::save_explain_data(Explain_table_access *eta, table_map prefix_tab
   tab->tracker= &eta->tracker;
   tab->jbuf_tracker= &eta->jbuf_tracker;
   
+  /* Enable the table access time tracker only for "ANALYZE stmt" */
+  if (thd->lex->analyze_stmt)
     tab->table->file->tracker= &eta->op_tracker;
-  /* id and select_type are kept in Explain_select */
+
+  /* No need to save id and select_type here, they are kept in Explain_select */
 
   /* table */
   if (table->derived_select_number)
@@ -23864,12 +23867,15 @@ int JOIN::save_explain_data_intern(Explain_query *output, bool need_tmp_table,
   if (message)
   {
     Explain_select *xpl_sel;
-    explain_node= xpl_sel= new (output->mem_root) Explain_select(output->mem_root);
+    explain_node= xpl_sel= 
+      new (output->mem_root) Explain_select(output->mem_root, 
+                                            thd->lex->analyze_stmt);
     join->select_lex->set_explain_type(true);
 
     xpl_sel->select_id= join->select_lex->select_number;
     xpl_sel->select_type= join->select_lex->type;
     xpl_sel->message= message;
+    tracker= &xpl_sel->time_tracker;
     if (select_lex->master_unit()->derived)
       xpl_sel->connection_type= Explain_node::EXPLAIN_NODE_DERIVED;
     /* Setting xpl_sel->message means that all other members are invalid */
@@ -23878,7 +23884,9 @@ int JOIN::save_explain_data_intern(Explain_query *output, bool need_tmp_table,
   else
   {
     Explain_select *xpl_sel;
-    explain_node= xpl_sel= new (output->mem_root) Explain_select(output->mem_root);
+    explain_node= xpl_sel= 
+      new (output->mem_root) Explain_select(output->mem_root, 
+                                            thd->lex->analyze_stmt);
     table_map used_tables=0;
     tracker= &xpl_sel->time_tracker;
 

sql/sql_select.h

@@ -1282,7 +1282,7 @@ public:
   bool optimized; ///< flag to avoid double optimization in EXPLAIN
   bool initialized; ///< flag to avoid double init_execution calls
 
-  Exec_time_tracker *tracker;
+  Time_and_counter_tracker *tracker;
   
   enum { QEP_NOT_PRESENT_YET, QEP_AVAILABLE, QEP_DELETED} have_query_plan;
 

sql/sql_update.cc

@@ -517,7 +517,9 @@ int mysql_update(THD *thd,
   */
   if (thd->lex->describe)
     goto produce_explain_and_leave;
-  query_plan.save_explain_data(thd->mem_root, thd->lex->explain);
+  explain= query_plan.save_explain_update_data(thd->mem_root, thd);
+
+  ANALYZE_START_TRACKING(&explain->command_tracker);
 
   DBUG_EXECUTE_IF("show_explain_probe_update_exec_start", 
                   dbug_serve_apcs(thd, 1););
@@ -721,7 +723,6 @@ int mysql_update(THD *thd,
   if (table->file->ha_table_flags() & HA_PARTIAL_COLUMN_READ)
     table->prepare_for_position();
 
-  explain= thd->lex->explain->get_upd_del_plan();
   table->reset_default_fields();
 
   /*
@@ -731,7 +732,6 @@ int mysql_update(THD *thd,
   */
   can_compare_record= records_are_comparable(table);
   explain->tracker.on_scan_init();
-  ANALYZE_START_TRACKING(&explain->time_tracker);
 
   while (!(error=info.read_record(&info)) && !thd->killed)
   {
@@ -908,7 +908,7 @@ int mysql_update(THD *thd,
       break;
     }
   }
-  ANALYZE_STOP_TRACKING(&explain->time_tracker);
+  ANALYZE_STOP_TRACKING(&explain->command_tracker);
   table->auto_increment_field_not_null= FALSE;
   dup_key_found= 0;
   /*
@@ -1046,7 +1046,7 @@ produce_explain_and_leave:
     We come here for various "degenerate" query plans: impossible WHERE,
     no-partitions-used, impossible-range, etc.
   */
-  query_plan.save_explain_data(thd->mem_root, thd->lex->explain);
+  query_plan.save_explain_update_data(thd->mem_root, thd);
 
 emit_explain_and_leave:
   int err2= thd->lex->explain->send_explain(thd);