diff options
Diffstat (limited to 'sql')
| -rw-r--r-- | sql/filesort.cc | 4 | ||||
| -rw-r--r-- | sql/handler.h | 4 | ||||
| -rw-r--r-- | sql/sql_analyze_stmt.cc | 17 | ||||
| -rw-r--r-- | sql/sql_analyze_stmt.h | 80 | ||||
| -rw-r--r-- | sql/sql_class.cc | 1 | ||||
| -rw-r--r-- | sql/sql_class.h | 17 | ||||
| -rw-r--r-- | sql/sql_delete.cc | 4 | ||||
| -rw-r--r-- | sql/sql_explain.cc | 5 | ||||
| -rw-r--r-- | sql/sql_explain.h | 2 | ||||
| -rw-r--r-- | sql/sql_select.cc | 12 | ||||
| -rw-r--r-- | sql/sql_update.cc | 4 |
11 files changed, 115 insertions, 35 deletions
diff --git a/sql/filesort.cc b/sql/filesort.cc index 3f4291cfb1f..bd6ac9d7374 100644 --- a/sql/filesort.cc +++ b/sql/filesort.cc @@ -196,7 +196,7 @@ SORT_INFO *filesort(THD *thd, TABLE *table, Filesort *filesort, else thd->inc_status_sort_scan(); thd->query_plan_flags|= QPLAN_FILESORT; - tracker->report_use(max_rows); + tracker->report_use(thd, max_rows); // If number of rows is not known, use as much of sort buffer as possible. num_rows= table->file->estimate_rows_upper_bound(); @@ -364,7 +364,7 @@ SORT_INFO *filesort(THD *thd, TABLE *table, Filesort *filesort, outfile->end_of_file=save_pos; } } - tracker->report_merge_passes_at_end(thd->query_plan_fsort_passes); + tracker->report_merge_passes_at_end(thd, thd->query_plan_fsort_passes); if (unlikely(error)) { int kill_errno= thd->killed_errno(); diff --git a/sql/handler.h b/sql/handler.h index c751817f5f1..f23476242a0 100644 --- a/sql/handler.h +++ b/sql/handler.h @@ -5008,12 +5008,12 @@ int binlog_log_row(TABLE* table, { \ Exec_time_tracker *this_tracker; \ if (unlikely((this_tracker= tracker))) \ - tracker->start_tracking(); \ + tracker->start_tracking(table->in_use); \ \ MYSQL_TABLE_IO_WAIT(PSI, OP, INDEX, FLAGS, PAYLOAD); \ \ if (unlikely(this_tracker)) \ - tracker->stop_tracking(); \ + tracker->stop_tracking(table->in_use); \ } void print_keydup_error(TABLE *table, KEY *key, const char *msg, myf errflag); diff --git a/sql/sql_analyze_stmt.cc b/sql/sql_analyze_stmt.cc index f1c6e2c73ea..fdabcf1e494 100644 --- a/sql/sql_analyze_stmt.cc +++ b/sql/sql_analyze_stmt.cc @@ -80,3 +80,20 @@ void Filesort_tracker::print_json_members(Json_writer *writer) } } +void attach_gap_time_tracker(THD *thd, Gap_time_tracker *gap_tracker, + ulonglong timeval) +{ + thd->gap_tracker_data.bill_to= gap_tracker; + thd->gap_tracker_data.start_time= timeval; +} + +void process_gap_time_tracker(THD *thd, ulonglong timeval) +{ + if (thd->gap_tracker_data.bill_to) + { + thd->gap_tracker_data.bill_to->log_time(thd->gap_tracker_data.start_time, + timeval); + thd->gap_tracker_data.bill_to= NULL; + } +} + diff --git a/sql/sql_analyze_stmt.h b/sql/sql_analyze_stmt.h index eec52822ae5..9d5151c3be2 100644 --- a/sql/sql_analyze_stmt.h +++ b/sql/sql_analyze_stmt.h @@ -38,6 +38,10 @@ $stmt"). */ +class Gap_time_tracker; +void attach_gap_time_tracker(THD *thd, Gap_time_tracker *gap_tracker, ulonglong timeval); +void process_gap_time_tracker(THD *thd, ulonglong timeval); + /* A class for tracking time it takes to do a certain action */ @@ -48,26 +52,37 @@ protected: ulonglong cycles; ulonglong last_start; - void cycles_stop_tracking() + void cycles_stop_tracking(THD *thd) { ulonglong end= my_timer_cycles(); cycles += end - last_start; if (unlikely(end < last_start)) cycles += ULONGLONG_MAX; + + process_gap_time_tracker(thd, end); + if (my_gap_tracker) + attach_gap_time_tracker(thd, my_gap_tracker, end); } public: - Exec_time_tracker() : count(0), cycles(0) {} - + Exec_time_tracker() : count(0), cycles(0), my_gap_tracker(NULL) {} + + /* + The time spent between stop_tracking() call on this object and any + other time measurement will be billed to this tracker. + */ + Gap_time_tracker *my_gap_tracker; + // interface for collecting time - void start_tracking() + void start_tracking(THD *thd) { last_start= my_timer_cycles(); + process_gap_time_tracker(thd, last_start); } - void stop_tracking() + void stop_tracking(THD *thd) { count++; - cycles_stop_tracking(); + cycles_stop_tracking(thd); } // interface for getting the time @@ -81,6 +96,31 @@ public: /* + Tracker for time spent between the calls to Exec_time_tracker's {start| + stop}_tracking(). + + @seealso Gap_time_tracker_data in sql_class.h +*/ +class Gap_time_tracker +{ + ulonglong cycles; +public: + Gap_time_tracker() : cycles(0) {} + + void log_time(ulonglong start, ulonglong end) { + cycles += end - start; + } + + double get_time_ms() const + { + // convert 'cycles' to milliseconds. + return 1000 * ((double)cycles) / sys_timer_info.cycles.frequency; + } +}; + + + +/* A class for counting certain actions (in all queries), and optionally collecting the timings (in ANALYZE queries). */ @@ -99,22 +139,22 @@ public: /* Unlike Exec_time_tracker::stop_tracking, we don't increase loops. */ - void stop_tracking() + void stop_tracking(THD *thd) { - cycles_stop_tracking(); + cycles_stop_tracking(thd); } }; -#define ANALYZE_START_TRACKING(tracker) \ +#define ANALYZE_START_TRACKING(thd, tracker) \ { \ (tracker)->incr_loops(); \ if (unlikely((tracker)->timed)) \ - { (tracker)->start_tracking(); } \ + { (tracker)->start_tracking(thd); } \ } -#define ANALYZE_STOP_TRACKING(tracker) \ +#define ANALYZE_STOP_TRACKING(thd, tracker) \ if (unlikely((tracker)->timed)) \ - { (tracker)->stop_tracking(); } + { (tracker)->stop_tracking(thd); } /* A class for collecting read statistics. @@ -186,14 +226,14 @@ public: /* Functions that filesort uses to report various things about its execution */ - inline void report_use(ha_rows r_limit_arg) + inline void report_use(THD *thd, ha_rows r_limit_arg) { if (!time_tracker.get_loops()) r_limit= r_limit_arg; else r_limit= (r_limit != r_limit_arg)? 0: r_limit_arg; - ANALYZE_START_TRACKING(&time_tracker); + ANALYZE_START_TRACKING(thd, &time_tracker); } inline void incr_pq_used() { r_used_pq++; } @@ -210,9 +250,9 @@ public: { sort_passes -= passes; } - inline void report_merge_passes_at_end(ulong passes) + inline void report_merge_passes_at_end(THD *thd, ulong passes) { - ANALYZE_STOP_TRACKING(&time_tracker); + ANALYZE_STOP_TRACKING(thd, &time_tracker); sort_passes += passes; } @@ -318,14 +358,14 @@ public: container_elements(0), n_checks(0), n_positive_checks(0) {} - inline void start_tracking() + inline void start_tracking(THD *thd) { - ANALYZE_START_TRACKING(&time_tracker); + ANALYZE_START_TRACKING(thd, &time_tracker); } - inline void stop_tracking() + inline void stop_tracking(THD *thd) { - ANALYZE_STOP_TRACKING(&time_tracker); + ANALYZE_STOP_TRACKING(thd, &time_tracker); } /* Save container buffer size in bytes */ diff --git a/sql/sql_class.cc b/sql/sql_class.cc index cc572065e92..0aca810692e 100644 --- a/sql/sql_class.cc +++ b/sql/sql_class.cc @@ -1336,6 +1336,7 @@ void THD::init() #endif //EMBEDDED_LIBRARY apc_target.init(&LOCK_thd_kill); + gap_tracker_data.init(); DBUG_VOID_RETURN; } diff --git a/sql/sql_class.h b/sql/sql_class.h index 2fb5797b325..0618bbdccbf 100644 --- a/sql/sql_class.h +++ b/sql/sql_class.h @@ -2141,6 +2141,22 @@ struct wait_for_commit extern "C" void my_message_sql(uint error, const char *str, myf MyFlags); +class Gap_time_tracker; + +/* + Thread context for Gap_time_tracker class. +*/ +class Gap_time_tracker_data +{ +public: + Gap_time_tracker_data(): bill_to(NULL) {} + + Gap_time_tracker *bill_to; + ulonglong start_time; + + void init() { bill_to = NULL; } +}; + /** A wrapper around thread_count. @@ -3326,6 +3342,7 @@ public: */ Apc_target apc_target; + Gap_time_tracker_data gap_tracker_data; #ifndef MYSQL_CLIENT enum enum_binlog_query_type { /* The query can be logged in row format or in statement format. */ diff --git a/sql/sql_delete.cc b/sql/sql_delete.cc index 0ea00a7d61c..b12312041bd 100644 --- a/sql/sql_delete.cc +++ b/sql/sql_delete.cc @@ -600,7 +600,7 @@ bool mysql_delete(THD *thd, TABLE_LIST *table_list, COND *conds, if (!(explain= query_plan.save_explain_delete_data(thd->mem_root, thd))) goto got_error; - ANALYZE_START_TRACKING(&explain->command_tracker); + ANALYZE_START_TRACKING(thd, &explain->command_tracker); DBUG_EXECUTE_IF("show_explain_probe_delete_exec_start", dbug_serve_apcs(thd, 1);); @@ -878,7 +878,7 @@ terminate_delete: table->file->ha_release_auto_increment(); if (options & OPTION_QUICK) (void) table->file->extra(HA_EXTRA_NORMAL); - ANALYZE_STOP_TRACKING(&explain->command_tracker); + ANALYZE_STOP_TRACKING(thd, &explain->command_tracker); cleanup: /* diff --git a/sql/sql_explain.cc b/sql/sql_explain.cc index d3b85638898..da727ba54fc 100644 --- a/sql/sql_explain.cc +++ b/sql/sql_explain.cc @@ -1811,10 +1811,11 @@ void Explain_table_access::print_explain_json(Explain_query *query, double total_time= op_tracker.get_time_ms(); if (rowid_filter) total_time+= rowid_filter->tracker->get_time_fill_container_ms(); - writer->add_member("r_total_time_ms").add_double(total_time); + writer->add_member("r_table_time_ms").add_double(total_time); + writer->add_member("r_other_time_ms").add_double(extra_time_tracker.get_time_ms()); } } - + /* `filtered` */ if (filtered_set) writer->add_member("filtered").add_double(filtered); diff --git a/sql/sql_explain.h b/sql/sql_explain.h index 3896636f9fd..bd8c8a4d499 100644 --- a/sql/sql_explain.h +++ b/sql/sql_explain.h @@ -835,6 +835,8 @@ public: /* Tracker for reading the table */ Table_access_tracker tracker; Exec_time_tracker op_tracker; + Gap_time_tracker extra_time_tracker; + Table_access_tracker jbuf_tracker; Explain_rowid_filter *rowid_filter; diff --git a/sql/sql_select.cc b/sql/sql_select.cc index 268fec84e3b..38f5b7a5a44 100644 --- a/sql/sql_select.cc +++ b/sql/sql_select.cc @@ -4168,9 +4168,9 @@ void JOIN::exec() select_lex->select_number)) dbug_serve_apcs(thd, 1); ); - ANALYZE_START_TRACKING(&explain->time_tracker); + ANALYZE_START_TRACKING(thd, &explain->time_tracker); exec_inner(); - ANALYZE_STOP_TRACKING(&explain->time_tracker); + ANALYZE_STOP_TRACKING(thd, &explain->time_tracker); DBUG_EXECUTE_IF("show_explain_probe_join_exec_end", if (dbug_user_var_equals_int(thd, @@ -13139,7 +13139,7 @@ void JOIN_TAB::build_range_rowid_filter_if_needed() Exec_time_tracker *table_tracker= table->file->get_time_tracker(); Rowid_filter_tracker *rowid_tracker= rowid_filter->get_tracker(); table->file->set_time_tracker(rowid_tracker->get_time_tracker()); - rowid_tracker->start_tracking(); + rowid_tracker->start_tracking(join->thd); if (!rowid_filter->build()) { is_rowid_filter_built= true; @@ -13149,7 +13149,7 @@ void JOIN_TAB::build_range_rowid_filter_if_needed() delete rowid_filter; rowid_filter= 0; } - rowid_tracker->stop_tracking(); + rowid_tracker->stop_tracking(join->thd); table->file->set_time_tracker(table_tracker); } } @@ -26076,8 +26076,10 @@ bool JOIN_TAB::save_explain_data(Explain_table_access *eta, /* Enable the table access time tracker only for "ANALYZE stmt" */ if (thd->lex->analyze_stmt) + { table->file->set_time_tracker(&eta->op_tracker); - + eta->op_tracker.my_gap_tracker = &eta->extra_time_tracker; + } /* No need to save id and select_type here, they are kept in Explain_select */ /* table */ diff --git a/sql/sql_update.cc b/sql/sql_update.cc index 9f298a51b72..26dfe5e40a2 100644 --- a/sql/sql_update.cc +++ b/sql/sql_update.cc @@ -666,7 +666,7 @@ int mysql_update(THD *thd, if (!(explain= query_plan.save_explain_update_data(query_plan.mem_root, thd))) goto err; - ANALYZE_START_TRACKING(&explain->command_tracker); + ANALYZE_START_TRACKING(thd, &explain->command_tracker); DBUG_EXECUTE_IF("show_explain_probe_update_exec_start", dbug_serve_apcs(thd, 1);); @@ -1168,7 +1168,7 @@ update_begin: break; } } - ANALYZE_STOP_TRACKING(&explain->command_tracker); + ANALYZE_STOP_TRACKING(thd, &explain->command_tracker); table->auto_increment_field_not_null= FALSE; dup_key_found= 0; /* |