Below is the list of changes that have just been committed into a local
5.1 repository of cmiller. When cmiller does a push these changes will
be propagated to the main repository and, within 24 hours after the
push, to the public repository.
For information on how to access the public repository
see http://dev.mysql.com/doc/mysql/en/installing-source-tree.html
ChangeSet@stripped, 2007-11-13 09:46:17-05:00, cmiller@stripped +4 -0
Insert profiling instructions into s-p code to make each statement
be profiled separately.
Expand the time formats in i_s.profiling to wide enough for larger
numbers.
mysql-test/r/profiling.result@stripped, 2007-11-13 09:46:15-05:00, cmiller@stripped +94 -0
Show that each query inside a procedure is profiled separately.
mysql-test/t/profiling.test@stripped, 2007-11-13 09:46:15-05:00, cmiller@stripped +41 -1
Show that each query inside a procedure is profiled separately.
sql/sp_head.cc@stripped, 2007-11-13 09:46:15-05:00, cmiller@stripped +30 -0
Poke profiling into stored-procedure code. For statement parts only
of routines, process them as profilable discrete queries.
sql/sql_profile.cc@stripped, 2007-11-13 09:46:15-05:00, cmiller@stripped +3 -1
Encode decimal size correctly.
diff -Nrup a/mysql-test/r/profiling.result b/mysql-test/r/profiling.result
--- a/mysql-test/r/profiling.result 2007-11-09 18:21:19 -05:00
+++ b/mysql-test/r/profiling.result 2007-11-13 09:46:15 -05:00
@@ -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 -Nrup a/mysql-test/t/profiling.test b/mysql-test/t/profiling.test
--- a/mysql-test/t/profiling.test 2007-11-09 18:21:19 -05:00
+++ b/mysql-test/t/profiling.test 2007-11-13 09:46:15 -05:00
@@ -138,13 +138,53 @@ 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';
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;
diff -Nrup a/sql/sp_head.cc b/sql/sp_head.cc
--- a/sql/sp_head.cc 2007-11-09 14:52:50 -05:00
+++ b/sql/sp_head.cc 2007-11-13 09:46:15 -05:00
@@ -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 *n
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 -Nrup a/sql/sql_profile.cc b/sql/sql_profile.cc
--- a/sql/sql_profile.cc 2007-11-09 20:29:00 -05:00
+++ b/sql/sql_profile.cc 2007-11-13 09:46:15 -05:00
@@ -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. */
| Thread |
|---|
| • bk commit into 5.1 tree (cmiller:1.2492) | Chad MILLER | 13 Nov |
