diff options
| -rw-r--r-- | mysql-test/r/profiling.result | 94 | ||||
| -rw-r--r-- | mysql-test/t/profiling.test | 42 | ||||
| -rw-r--r-- | sql/sp_head.cc | 30 | ||||
| -rw-r--r-- | sql/sql_profile.cc | 4 |
4 files changed, 168 insertions, 2 deletions
diff --git a/mysql-test/r/profiling.result b/mysql-test/r/profiling.result index 6435b346f98..1673597d544 100644 --- a/mysql-test/r/profiling.result +++ b/mysql-test/r/profiling.result @@ -300,6 +300,100 @@ id select @@profiling; @@profiling 1 +set session profiling = OFF; +drop table if exists profile_log; +Warnings: +Note 1051 Unknown table 'profile_log' +create table profile_log (how_many int); +drop procedure if exists p1; +drop procedure if exists p2; +drop procedure if exists p3; +create procedure p1 () modifies sql data begin set profiling = ON; select 'This p1 should show up in profiling'; insert into profile_log select count(*) from information_schema.profiling; end// +create procedure p2() deterministic begin set profiling = ON; call p1(); select 'This p2 should show up in profiling'; end// +create procedure p3 () reads sql data begin set profiling = ON; select 'This p3 should show up in profiling'; show profile; end// +select count(*) as count_before_p1 from information_schema.profiling; +count_before_p1 +535 +first call to p1 +call p1; +This p1 should show up in profiling +This p1 should show up in profiling +select * from profile_log; +how_many +528 +second call to p1 +call p1; +This p1 should show up in profiling +This p1 should show up in profiling +select * from profile_log; +how_many +528 +478 +third call to p1 +call p1; +This p1 should show up in profiling +This p1 should show up in profiling +select * from profile_log; +how_many +528 +478 +443 +set session profiling = OFF; +call p2; +This p1 should show up in profiling +This p1 should show up in profiling +This p2 should show up in profiling +This p2 should show up in profiling +set session profiling = OFF; +call p3; +This p3 should show up in profiling +This p3 should show up in profiling +Status Duration +continuing inside routine # +checking permissions # +Opening tables # +init # +optimizing # +executing # +end # +query end # +closing tables # +show profiles; +Query_ID Duration Query +# # create table t3 (id int not null primary key) +# # insert into t1 values (1), (2), (3) +# # insert into t2 values (1), (2), (3) +# # insert into t3 values (1), (2), (3) +# # select * from t1 +# # delete from t1 +# # insert into t1 values (1), (2), (3) +# # insert into t1 values (1), (2), (3) +# # select * from t1 +# # select @@profiling +# # create function f1() returns varchar(50) return 'hello' +# # select @@profiling +# # select @@profiling +# # select 'This p1 should show up in profiling' +# # insert into profile_log select count(*) from information_schema.profiling +# # select * from profile_log +# # SET profiling = ON +# # select 'This p1 should show up in profiling' +# # insert into profile_log select count(*) from information_schema.profiling +# # select * from profile_log +# # SET profiling = ON +# # select 'This p1 should show up in profiling' +# # insert into profile_log select count(*) from information_schema.profiling +# # select * from profile_log +# # SET profiling = ON +# # select 'This p1 should show up in profiling' +# # insert into profile_log select count(*) from information_schema.profiling +# # select 'This p2 should show up in profiling' +# # select 'This p3 should show up in profiling' +# # show profile +drop procedure if exists p1; +drop procedure if exists p2; +drop procedure if exists p3; +drop table if exists profile_log; set session profiling = ON; drop table if exists t2; create table t2 (id int not null); diff --git a/mysql-test/t/profiling.test b/mysql-test/t/profiling.test index 9e73c63a977..9e5328e030f 100644 --- a/mysql-test/t/profiling.test +++ b/mysql-test/t/profiling.test @@ -138,7 +138,7 @@ show profiles; ## Verify that the various juggling of THD contexts doesn't affect profiling. -## Functions +## Functions and procedures set session profiling = ON; select @@profiling; create function f1() returns varchar(50) return 'hello'; @@ -146,6 +146,46 @@ select @@profiling; select * from t1 where id <> f1(); select @@profiling; +set session profiling = OFF; +drop table if exists profile_log; +create table profile_log (how_many int); + +--disable_warnings +drop procedure if exists p1; +drop procedure if exists p2; +drop procedure if exists p3; +--enable_warnings + +delimiter //; +create procedure p1 () modifies sql data begin set profiling = ON; select 'This p1 should show up in profiling'; insert into profile_log select count(*) from information_schema.profiling; end// +create procedure p2() deterministic begin set profiling = ON; call p1(); select 'This p2 should show up in profiling'; end// +create procedure p3 () reads sql data begin set profiling = ON; select 'This p3 should show up in profiling'; show profile; end// +delimiter ;// + +select count(*) as count_before_p1 from information_schema.profiling; +--echo first call to p1 +call p1; +select * from profile_log; +--echo second call to p1 +call p1; +select * from profile_log; +--echo third call to p1 +call p1; +select * from profile_log; +set session profiling = OFF; +call p2; +set session profiling = OFF; +--replace_column 2 # +call p3; + +--replace_column 1 # 2 # +show profiles; + +drop procedure if exists p1; +drop procedure if exists p2; +drop procedure if exists p3; +drop table if exists profile_log; + ## Triggers set session profiling = ON; drop table if exists t2; diff --git a/sql/sp_head.cc b/sql/sp_head.cc index 09ae572152f..3becfd6bcf4 100644 --- a/sql/sp_head.cc +++ b/sql/sp_head.cc @@ -1162,15 +1162,36 @@ sp_head::execute(THD *thd) */ thd->spcont->callers_arena= &backup_arena; +#if defined(ENABLED_PROFILING) && defined(COMMUNITY_SERVER) + /* Discard the initial part of executing routines. */ + thd->profiling.discard_current_query(); +#endif do { sp_instr *i; uint hip; // Handler ip +#if defined(ENABLED_PROFILING) && defined(COMMUNITY_SERVER) + /* + Treat each "instr" of a routine as discrete unit that could be profiled. + Profiling only records information for segments of code that set the + source of the query, and almost all kinds of instructions in s-p do not. + */ + thd->profiling.finish_current_query(); + thd->profiling.start_new_query("continuing inside routine"); +#endif + i = get_instr(ip); // Returns NULL when we're done. if (i == NULL) + { +#if defined(ENABLED_PROFILING) && defined(COMMUNITY_SERVER) + thd->profiling.discard_current_query(); +#endif break; + } + DBUG_PRINT("execute", ("Instruction %u", ip)); + /* Don't change NOW() in FUNCTION or TRIGGER */ if (!thd->in_sub_stmt) thd->set_time(); // Make current_time() et al work @@ -1248,6 +1269,11 @@ sp_head::execute(THD *thd) } } while (!err_status && !thd->killed); +#if defined(ENABLED_PROFILING) && defined(COMMUNITY_SERVER) + thd->profiling.finish_current_query(); + thd->profiling.start_new_query("tail end of routine"); +#endif + /* Restore query context. */ m_creation_ctx->restore_env(thd, saved_creation_ctx); @@ -2725,6 +2751,10 @@ sp_instr_stmt::execute(THD *thd, uint *nextp) query= thd->query; query_length= thd->query_length; +#if defined(ENABLED_PROFILING) && defined(COMMUNITY_SERVER) + /* This s-p instr is profilable and will be captured. */ + thd->profiling.set_query_source(m_query.str, m_query.length); +#endif if (!(res= alloc_query(thd, m_query.str, m_query.length)) && !(res=subst_spvars(thd, this, &m_query))) { diff --git a/sql/sql_profile.cc b/sql/sql_profile.cc index fd2ae32c711..1922fa3bc2b 100644 --- a/sql/sql_profile.cc +++ b/sql/sql_profile.cc @@ -33,7 +33,9 @@ #include "my_sys.h" #define TIME_FLOAT_DIGITS 9 -#define TIME_I_S_DECIMAL_SIZE (6*100)+6 /**< two vals encoded: (dec*100)+len */ +/** two vals encoded: (dec*100)+len */ +#define TIME_I_S_DECIMAL_SIZE (TIME_FLOAT_DIGITS*100)+(TIME_FLOAT_DIGITS-3) + #define MAX_QUERY_LENGTH 300 /* Reserved for systems that can't record the function name in source. */ |