database/mariadb
1
0
Fork 0
mirror of https://github.com/MariaDB/server.git synced 2025-07-10 04:22:00 +03:00
Code Activity

Push history-limiting code until after the code that adds new

Browse Source 
history entries.  Lazy deletion isn't smart or useful here.

Backport from 5.1 .
This commit is contained in:
cmiller@zippy.cornsilk.net
2007-11-14 15:11:58 -05:00
parent 1604cdb30d
commit ddb1443b07
10 changed files with 464 additions and 283 deletions
Download Patch File Download Diff File Expand all files Collapse all files

1
include/my_sys.h
View File

@ -162,6 +162,7 @@ extern char *my_strdup_with_length(const char *from, uint length,
#define ORIG_CALLER_INFO /* nothing */
#define TRASH(A,B) /* nothing */
#endif
#define my_strndup(A,B,C) my_strdup_with_length((A), (B), (C))
#ifdef HAVE_LARGE_PAGES
extern uint my_get_large_page_size(void);

47
mysql-test/r/profiling.result
View File

@ -300,6 +300,53 @@ 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//
first call to p1
call p1;
select * from profile_log;
second call to p1
call p1;
select * from profile_log;
third call to p1
call p1;
select * from profile_log;
set session profiling = OFF;
call p2;
set session profiling = OFF;
call p3;
show profiles;
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);

66
mysql-test/t/profiling.test
View File

@ -136,7 +136,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';
@ -144,6 +144,64 @@ 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 ;//
--disable_result_log
--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;
call p3;
--replace_column 1 # 2 #
show profiles;
--enable_result_log
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;
@ -193,6 +251,12 @@ drop table if exists t1, t2, t3;
drop view if exists v1;
drop function if exists f1;
## Multiple queries in one packet. Combo statements don't work with ps-proto.
#--eval select 1; select 2; select 3;
## two continuations, one starting
#select state from information_schema.profiling where seq=1 order by query_id desc limit 3;
## last thing in the file
set session profiling = OFF;

14
sql/mysql_priv.h
View File

@ -495,6 +495,8 @@ enum enum_parsing_place
struct st_table;
class THD;
#define thd_proc_info(thd, msg) set_thd_proc_info(thd, msg, __func__, __FILE__, __LINE__)
/* Struct to handle simple linked lists */
typedef struct st_sql_list {
@ -580,6 +582,16 @@ typedef Comp_creator* (*chooser_compare_func_creator)(bool invert);
#include "item.h"
extern my_decimal decimal_zero;
/**
The meat of thd_proc_info(THD*, char*), a macro that packs the last
three calling-info parameters.
*/
extern "C"
const char *set_thd_proc_info(THD *thd, const char *info,
const char *calling_func,
const char *calling_file,
const unsigned int calling_line);
/* sql_parse.cc */
void free_items(Item *item);
void cleanup_items(Item *item);
@ -978,6 +990,8 @@ bool get_schema_tables_result(JOIN *join,
enum enum_schema_table_state executed_place);
enum enum_schema_tables get_schema_table_idx(ST_SCHEMA_TABLE *schema_table);
bool schema_table_store_record(THD *thd, TABLE *table);
#define is_schema_db(X) \
!my_strcasecmp(system_charset_info, INFORMATION_SCHEMA_NAME.str, (X))

29
sql/sp_head.cc
View File

@ -1057,15 +1057,36 @@ sp_head::execute(THD *thd)
*/
thd->spcont->callers_arena= &backup_arena;
#if defined(ENABLED_PROFILING)
/* 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)
/*
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)
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
@ -1142,6 +1163,10 @@ sp_head::execute(THD *thd)
}
} while (!err_status && !thd->killed);
#if defined(ENABLED_PROFILING)
thd->profiling.finish_current_query();
thd->profiling.start_new_query("tail end of routine");
#endif
thd->restore_active_arena(&execute_arena, &backup_arena);
thd->spcont->pop_all_cursors(); // To avoid memory leaks after an error
@ -2539,6 +2564,10 @@ sp_instr_stmt::execute(THD *thd, uint *nextp)
query= thd->query;
query_length= thd->query_length;
#if defined(ENABLED_PROFILING)
/* 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+1)) &&
!(res=subst_spvars(thd, this, &m_query)))
{

14
sql/sql_class.cc
View File

@ -165,6 +165,20 @@ Open_tables_state::Open_tables_state(ulong version_arg)
reset_open_tables_state();
}
extern "C"
const char *set_thd_proc_info(THD *thd, const char *info,
const char *calling_function,
const char *calling_file,
const unsigned int calling_line)
{
const char *old_info= thd->proc_info;
DBUG_PRINT("proc_info", ("%s:%d %s", calling_file, calling_line, info));
#if defined(ENABLED_PROFILING)
thd->profiling.status_change(info, calling_function, calling_file, calling_line);
#endif
thd->proc_info= info;
return old_info;
}
THD::THD()

44
sql/sql_parse.cc
View File

@ -1313,6 +1313,10 @@ pthread_handler_t handle_bootstrap(void *arg)
thd->db_length+1+QUERY_CACHE_FLAGS_SIZE);
thd->query[length] = '\0';
DBUG_PRINT("query",("%-.4096s",thd->query));
#if defined(ENABLED_PROFILING)
thd->profiling.set_query_source(thd->query, length);
#endif
/*
We don't need to obtain LOCK_thread_count here because in bootstrap
mode we have only one thread.
@ -1522,6 +1526,7 @@ int end_trans(THD *thd, enum enum_mysql_completiontype completion)
bool do_command(THD *thd)
{
bool return_value;
char *packet= 0;
ulong packet_length;
NET *net= &thd->net;
@ -1545,7 +1550,12 @@ bool do_command(THD *thd)
thd->clear_error(); // Clear error message
net_new_transaction(net);
if ((packet_length=my_net_read(net)) == packet_error)
packet_length= my_net_read(net);
#if defined(ENABLED_PROFILING)
thd->profiling.start_new_query();
#endif
if (packet_length == packet_error)
{
DBUG_PRINT("info",("Got error %d reading command from socket %s",
net->error,
@ -1554,11 +1564,13 @@ bool do_command(THD *thd)
if (net->error != 3)
{
statistic_increment(aborted_threads,&LOCK_status);
DBUG_RETURN(TRUE); // We have to close it.
return_value= TRUE; // We have to close it.
goto out;
}
net_send_error(thd, net->last_errno, NullS);
net->error= 0;
DBUG_RETURN(FALSE);
return_value= FALSE;
goto out;
}
else
{
@ -1583,7 +1595,13 @@ bool do_command(THD *thd)
command == packet[0] == COM_SLEEP).
In dispatch_command packet[packet_length] points beyond the end of packet.
*/
DBUG_RETURN(dispatch_command(command,thd, packet+1, (uint) packet_length));
return_value= dispatch_command(command, thd, packet+1, (uint) (packet_length));
out:
#if defined(ENABLED_PROFILING)
thd->profiling.finish_current_query();
#endif
DBUG_RETURN(return_value);
}
#endif /* EMBEDDED_LIBRARY */
@ -1805,6 +1823,9 @@ bool dispatch_command(enum enum_server_command command, THD *thd,
mysql_log.write(thd,command, format, thd->query_length, thd->query);
DBUG_PRINT("query",("%-.4096s",thd->query));
#if defined(ENABLED_PROFILING)
thd->profiling.set_query_source(thd->query, thd->query_length);
#endif
if (!(specialflag & SPECIAL_NO_PRIOR))
my_pthread_setprio(pthread_self(),QUERY_PRIOR);
@ -1831,6 +1852,13 @@ bool dispatch_command(enum enum_server_command command, THD *thd,
next_packet++;
length--;
}
#if defined(ENABLED_PROFILING)
thd->profiling.finish_current_query();
thd->profiling.start_new_query("continuing");
thd->profiling.set_query_source(next_packet, length);
#endif
VOID(pthread_mutex_lock(&LOCK_thread_count));
thd->query_length= length;
thd->query= next_packet;
@ -2325,7 +2353,7 @@ int prepare_schema_table(THD *thd, LEX *lex, Table_ident *table_ident,
wish to have SHOW commands show up in profiling.
*/
#ifdef ENABLED_PROFILING
thd->profiling.discard();
thd->profiling.discard_current_query();
#endif
break;
case SCH_OPEN_TABLES:
@ -2762,8 +2790,7 @@ mysql_execute_command(THD *thd)
case SQLCOM_SHOW_PROFILES:
{
#ifdef ENABLED_PROFILING
thd->profiling.store();
thd->profiling.discard();
thd->profiling.discard_current_query();
res= thd->profiling.show_profiles();
if (res)
goto error;
@ -5887,9 +5914,6 @@ void mysql_reset_thd_for_next_command(THD *thd)
thd->total_warn_count=0; // Warnings for this query
thd->rand_used= 0;
thd->sent_row_count= thd->examined_row_count= 0;
#ifdef ENABLED_PROFILING
thd->profiling.reset();
#endif
}
DBUG_VOID_RETURN;
}

349
sql/sql_profile.cc
View File

@ -14,13 +14,29 @@
Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA */
/**
@file
Implement query profiling as as list of metaphorical fences, with one fence
per query, and each fencepost a change of thd->proc_info state (with a
snapshot of system statistics). When asked, we can then iterate over the
fenceposts and calculate the distance between them, to inform the user what
happened during a particular query or thd->proc_info state.
User variables that inform profiling behavior:
- "profiling", boolean, session only, "Are queries profiled?"
- "profiling_history_size", integer, session + global, "Num queries stored?"
*/
#include "mysql_priv.h"
#include "my_sys.h"
#define TIME_FLOAT_DIGITS 9
#define MAX_QUERY_LENGTH 300
/** two vals encoded: (dec*100)+len */
#define TIME_I_S_DECIMAL_SIZE (TIME_FLOAT_DIGITS*100)+(TIME_FLOAT_DIGITS-3)
bool schema_table_store_record(THD *thd, TABLE *table);
#define MAX_QUERY_LENGTH 300
/* Reserved for systems that can't record the function name in source. */
const char * const _unknown_func_ = "<unknown>";
@ -31,22 +47,23 @@ const char * const _unknown_func_ = "<unknown>";
int fill_query_profile_statistics_info(THD *thd, TABLE_LIST *tables,
Item *cond)
{
#ifdef ENABLED_PROFILING
#if defined(ENABLED_PROFILING)
return(thd->profiling.fill_statistics_info(thd, tables, cond));
#else
my_error(ER_FEATURE_DISABLED, MYF(0), "SHOW PROFILE", "enable-profiling");
return(1);
#endif
}
ST_FIELD_INFO query_profile_statistics_info[]=
{
/* name, length, type, value, maybe_null, old_name */
/* name, length, type, value, maybe_null, old_name, open_method */
{"QUERY_ID", 20, MYSQL_TYPE_LONG, 0, false, "Query_id"},
{"SEQ", 20, MYSQL_TYPE_LONG, 0, false, "Seq"},
{"STATE", 30, MYSQL_TYPE_STRING, 0, false, "Status"},
{"DURATION", TIME_FLOAT_DIGITS, MYSQL_TYPE_DECIMAL, 0, false, "Duration"},
{"CPU_USER", TIME_FLOAT_DIGITS, MYSQL_TYPE_DECIMAL, 0, true, "CPU_user"},
{"CPU_SYSTEM", TIME_FLOAT_DIGITS, MYSQL_TYPE_DECIMAL, 0, true, "CPU_system"},
{"DURATION", TIME_I_S_DECIMAL_SIZE, MYSQL_TYPE_DECIMAL, 0, false, "Duration"},
{"CPU_USER", TIME_I_S_DECIMAL_SIZE, MYSQL_TYPE_DECIMAL, 0, true, "CPU_user"},
{"CPU_SYSTEM", TIME_I_S_DECIMAL_SIZE, MYSQL_TYPE_DECIMAL, 0, true, "CPU_system"},
{"CONTEXT_VOLUNTARY", 20, MYSQL_TYPE_LONG, 0, true, "Context_voluntary"},
{"CONTEXT_INVOLUNTARY", 20, MYSQL_TYPE_LONG, 0, true, "Context_involuntary"},
{"BLOCK_OPS_IN", 20, MYSQL_TYPE_LONG, 0, true, "Block_ops_in"},
@ -59,7 +76,7 @@ ST_FIELD_INFO query_profile_statistics_info[]=
{"SOURCE_FUNCTION", 30, MYSQL_TYPE_STRING, 0, true, "Source_function"},
{"SOURCE_FILE", 20, MYSQL_TYPE_STRING, 0, true, "Source_file"},
{"SOURCE_LINE", 20, MYSQL_TYPE_LONG, 0, true, "Source_line"},
{NULL, 0, MYSQL_TYPE_STRING, 0, true, NULL}
{NULL, 0, MYSQL_TYPE_STRING, 0, true, NULL}
};
@ -112,45 +129,41 @@ int make_profile_table_for_show(THD *thd, ST_SCHEMA_TABLE *schema_table)
}
#ifdef ENABLED_PROFILING
#if defined(ENABLED_PROFILING)
#define RUSAGE_USEC(tv) ((tv).tv_sec*1000*1000 + (tv).tv_usec)
#define RUSAGE_DIFF_USEC(tv1, tv2) (RUSAGE_USEC((tv1))-RUSAGE_USEC((tv2)))
PROFILE_ENTRY::PROFILE_ENTRY()
:profile(NULL), status(NULL), function(NULL), file(NULL), line(0),
time_usecs(0.0), allocated_status_memory(NULL)
{
collect();
/* The beginning of the query, before any state is set. */
set_status("(initialization)", NULL, NULL, 0);
}
PROFILE_ENTRY::PROFILE_ENTRY(QUERY_PROFILE *profile_arg, const char *status_arg)
PROF_MEASUREMENT::PROF_MEASUREMENT(QUERY_PROFILE *profile_arg, const char
*status_arg)
:profile(profile_arg)
{
collect();
set_status(status_arg, NULL, NULL, 0);
set_label(status_arg, NULL, NULL, 0);
}
PROFILE_ENTRY::PROFILE_ENTRY(QUERY_PROFILE *profile_arg, const char *status_arg,
const char *function_arg,
const char *file_arg, unsigned int line_arg)
PROF_MEASUREMENT::PROF_MEASUREMENT(QUERY_PROFILE *profile_arg,
const char *status_arg,
const char *function_arg,
const char *file_arg,
unsigned int line_arg)
:profile(profile_arg)
{
collect();
set_status(status_arg, function_arg, file_arg, line_arg);
set_label(status_arg, function_arg, file_arg, line_arg);
}
PROFILE_ENTRY::~PROFILE_ENTRY()
PROF_MEASUREMENT::~PROF_MEASUREMENT()
{
if (allocated_status_memory != NULL)
my_free(allocated_status_memory, MYF(0));
status= function= file= NULL;
}
void PROFILE_ENTRY::set_status(const char *status_arg, const char *function_arg, const char *file_arg, unsigned int line_arg)
void PROF_MEASUREMENT::set_label(const char *status_arg,
const char *function_arg,
const char *file_arg, unsigned int line_arg)
{
size_t sizes[3]; /* 3 == status+function+file */
char *cursor;
@ -198,7 +211,15 @@ void PROFILE_ENTRY::set_status(const char *status_arg, const char *function_arg,
line= line_arg;
}
void PROFILE_ENTRY::collect()
/**
This updates the statistics for this moment of time. It captures the state
of the running system, so later we can compare points in time and infer what
happened in the mean time. It should only be called immediately upon
instantiation of this PROF_MEASUREMENT.
@todo Implement resource capture for OSes not like BSD.
*/
void PROF_MEASUREMENT::collect()
{
time_usecs= (double) my_getsystime() / 10.0; /* 1 sec was 1e7, now is 1e6 */
#ifdef HAVE_GETRUSAGE
@ -206,28 +227,13 @@ void PROFILE_ENTRY::collect()
#endif
}
QUERY_PROFILE::QUERY_PROFILE(PROFILING *profiling_arg, char *query_source_arg,
uint query_length_arg)
:profiling(profiling_arg), server_query_id(0), profiling_query_id(0),
query_source(NULL)
QUERY_PROFILE::QUERY_PROFILE(PROFILING *profiling_arg, const char *status_arg)
:profiling(profiling_arg), profiling_query_id(0), query_source(NULL)
{
profile_end= &profile_start;
set_query_source(query_source_arg, query_length_arg);
}
void QUERY_PROFILE::set_query_source(char *query_source_arg,
uint query_length_arg)
{
if (! profiling->enabled)
return;
/* Truncate to avoid DoS attacks. */
uint length= min(MAX_QUERY_LENGTH, query_length_arg);
/* TODO?: Provide a way to include the full text, as in SHOW PROCESSLIST. */
DBUG_ASSERT(query_source == NULL);
if (query_source_arg != NULL)
query_source= my_strdup_with_length(query_source_arg, length, MYF(0));
profile_start= new PROF_MEASUREMENT(this, status_arg);
entries.push_back(profile_start);
profile_end= profile_start;
}
QUERY_PROFILE::~QUERY_PROFILE()
@ -239,61 +245,44 @@ QUERY_PROFILE::~QUERY_PROFILE()
my_free(query_source, MYF(0));
}
void QUERY_PROFILE::status(const char *status_arg,
const char *function_arg= NULL,
const char *file_arg= NULL, unsigned int line_arg= 0)
/**
@todo Provide a way to include the full text, as in SHOW PROCESSLIST.
*/
void QUERY_PROFILE::set_query_source(char *query_source_arg,
uint query_length_arg)
{
THD *thd= profiling->thd;
PROFILE_ENTRY *prof;
/* Truncate to avoid DoS attacks. */
uint length= min(MAX_QUERY_LENGTH, query_length_arg);
DBUG_ASSERT(query_source == NULL); /* we don't leak memory */
if (query_source_arg != NULL)
query_source= my_strndup(query_source_arg, length, MYF(0));
}
void QUERY_PROFILE::new_status(const char *status_arg,
const char *function_arg, const char *file_arg,
unsigned int line_arg)
{
PROF_MEASUREMENT *prof;
DBUG_ENTER("QUERY_PROFILE::status");
/* Blank status. Just return, and thd->proc_info will be set blank later. */
if (unlikely(status_arg == NULL))
DBUG_VOID_RETURN;
DBUG_ASSERT(status_arg != NULL);
/* If thd->proc_info is currently set to status_arg, don't profile twice. */
if (likely((thd->proc_info != NULL) &&
((thd->proc_info == status_arg) ||
(strcmp(thd->proc_info, status_arg) == 0))))
{
DBUG_VOID_RETURN;
}
/* Is this the same query as our profile currently contains? */
if (unlikely((thd->query_id != server_query_id) && !thd->spcont))
reset();
if (function_arg && file_arg)
{
if ((profile_end= prof= new PROFILE_ENTRY(this, status_arg, function_arg,
file_arg, line_arg)))
entries.push_back(prof);
}
if ((function_arg != NULL) && (file_arg != NULL))
prof= new PROF_MEASUREMENT(this, status_arg, function_arg, file_arg, line_arg);
else
{
if ((profile_end= prof= new PROFILE_ENTRY(this, status_arg)))
entries.push_back(prof);
}
prof= new PROF_MEASUREMENT(this, status_arg);
profile_end= prof;
entries.push_back(prof);
DBUG_VOID_RETURN;
}
void QUERY_PROFILE::reset()
{
DBUG_ENTER("QUERY_PROFILE::reset");
if (likely(profiling->thd->query_id != server_query_id))
{
server_query_id= profiling->thd->query_id; /* despite name, is global */
profile_start.collect();
while (! entries.is_empty())
delete entries.pop();
}
DBUG_VOID_RETURN;
}
PROFILING::PROFILING()
:profile_id_counter(1), keeping(TRUE), enabled(FALSE), current(NULL), last(NULL)
:profile_id_counter(1), current(NULL), last(NULL)
{
}
@ -306,57 +295,98 @@ PROFILING::~PROFILING()
delete current;
}
/**
A new state is given, and that signals the profiler to start a new
timed step for the current query's profile.
@param status_arg name of this step
@param function_arg calling function (usually supplied from compiler)
@param function_arg calling file (usually supplied from compiler)
@param function_arg calling line number (usually supplied from compiler)
*/
void PROFILING::status_change(const char *status_arg,
const char *function_arg,
const char *file_arg, unsigned int line_arg)
{
DBUG_ENTER("PROFILING::status_change");
if (status_arg == NULL) /* We don't know how to handle that */
DBUG_VOID_RETURN;
if (current == NULL) /* This profile was already discarded. */
DBUG_VOID_RETURN;
if (unlikely(enabled))
{
if (unlikely(current == NULL))
reset();
current->new_status(status_arg, function_arg, file_arg, line_arg);
DBUG_ASSERT(current != NULL);
current->status(status_arg, function_arg, file_arg, line_arg);
}
thd->proc_info= status_arg;
DBUG_VOID_RETURN;
}
void PROFILING::store()
{
DBUG_ENTER("PROFILING::store");
/**
Prepare to start processing a new query. It is an error to do this
if there's a query already in process; nesting is not supported.
/* Already stored */
if (unlikely((last != NULL) &&
(current != NULL) &&
(last->server_query_id == current->server_query_id)))
@param initial_state (optional) name of period before first state change
*/
void PROFILING::start_new_query(const char *initial_state)
{
DBUG_ENTER("PROFILING::start_new_query");
/* This should never happen unless the server is radically altered. */
if (unlikely(current != NULL))
{
DBUG_VOID_RETURN;
DBUG_PRINT("warning", ("profiling code was asked to start a new query "
"before the old query was finished. This is "
"probably a bug."));
finish_current_query();
}
while (history.elements > thd->variables.profiling_history_size)
delete history.pop();
enabled= (((thd)->options & OPTION_PROFILING) != 0);
if (likely(((thd)->options & OPTION_PROFILING) == 0))
DBUG_VOID_RETURN;
if (! enabled) DBUG_VOID_RETURN;
DBUG_ASSERT(current == NULL);
current= new QUERY_PROFILE(this, initial_state);
DBUG_VOID_RETURN;
}
/**
Throw away the current profile, because it's useless or unwanted
or corrupted.
*/
void PROFILING::discard_current_query()
{
DBUG_ENTER("PROFILING::discard_current_profile");
delete current;
current= NULL;
DBUG_VOID_RETURN;
}
/**
Try to save the current profile entry, clean up the data if it shouldn't be
saved, and maintain the profile history size. Naturally, this may not
succeed if the profile was previously discarded, and that's expected.
*/
void PROFILING::finish_current_query()
{
DBUG_ENTER("PROFILING::finish_current_profile");
if (current != NULL)
{
if (keeping &&
(enabled) && /* ON at start? */
(((thd)->options & OPTION_PROFILING) != 0) && /* and ON at end? */
/* The last fence-post, so we can support the span before this. */
status_change("ending", NULL, NULL, 0);
if ((enabled) && /* ON at start? */
((thd->options & OPTION_PROFILING) != 0) && /* and ON at end? */
(current->query_source != NULL) &&
(current->query_source[0] != '\0') &&
(!current->entries.is_empty()))
(! current->entries.is_empty()))
{
current->profiling_query_id= next_profile_id(); /* assign an id */
last= current; /* never contains something that is not in the history. */
history.push_back(current);
last= current; /* never contains something that is not in the history. */
current= NULL;
}
else
@ -366,35 +396,9 @@ void PROFILING::store()
}
}
DBUG_ASSERT(current == NULL);
if (enabled)
current= new QUERY_PROFILE(this, thd->query, thd->query_length);
DBUG_VOID_RETURN;
}
/**
Store and clean up the old information and get ready to hold info about this
new query. This is called very often so it must be very lightweight if
profiling is not active.
*/
void PROFILING::reset()
{
DBUG_ENTER("PROFILING::reset");
store();
if (likely(((thd)->options & OPTION_PROFILING) == 0))
{
enabled= FALSE;
DBUG_VOID_RETURN;
}
else
enabled= TRUE;
if (current != NULL)
current->reset();
keep();
/* Maintain the history size. */
while (history.elements > thd->variables.profiling_history_size)
delete history.pop();
DBUG_VOID_RETURN;
}
@ -431,8 +435,8 @@ bool PROFILING::show_profiles()
String elapsed;
PROFILE_ENTRY *ps= &prof->profile_start;
PROFILE_ENTRY *pe= prof->profile_end;
PROF_MEASUREMENT *ps= prof->profile_start;
PROF_MEASUREMENT *pe= prof->profile_end;
if (++idx <= unit->offset_limit_cnt)
continue;
@ -456,16 +460,18 @@ bool PROFILING::show_profiles()
DBUG_RETURN(FALSE);
}
/*
This is an awful hack to let prepared statements tell us the query
that they're executing.
/**
At a point in execution where we know the query source, save the text
of it in the query profile.
This must be called exactly once per descrete statement.
*/
void PROFILING::set_query_source(char *query_source_arg, uint query_length_arg)
{
DBUG_ENTER("PROFILING::set_query_source");
/* We can't get this query source through normal means. */
DBUG_ASSERT((thd->query == NULL) || (thd->query_length == 0));
if (! enabled)
DBUG_VOID_RETURN;
if (current != NULL)
current->set_query_source(query_source_arg, query_length_arg);
@ -474,7 +480,6 @@ void PROFILING::set_query_source(char *query_source_arg, uint query_length_arg)
DBUG_VOID_RETURN;
}
/**
Fill the information schema table, "query_profile", as defined in show.cc .
There are two ways to get to this function: Selecting from the information
@ -494,7 +499,6 @@ int PROFILING::fill_statistics_info(THD *thd, TABLE_LIST *tables, Item *cond)
history_iterator= history.iterator_next(history_iterator))
{
query= history.iterator_value(history_iterator);
PROFILE_ENTRY *previous= &(query->profile_start);
/*
Because we put all profiling info into a table that may be reordered, let
@ -504,7 +508,7 @@ int PROFILING::fill_statistics_info(THD *thd, TABLE_LIST *tables, Item *cond)
ulonglong seq;
void *entry_iterator;
PROFILE_ENTRY *entry;
PROF_MEASUREMENT *entry, *previous= NULL;
/* ...and for each query, go through all its state-change steps. */
for (seq= 0, entry_iterator= query->entries.new_iterator();
entry_iterator != NULL;
@ -513,6 +517,9 @@ int PROFILING::fill_statistics_info(THD *thd, TABLE_LIST *tables, Item *cond)
{
entry= query->entries.iterator_value(entry_iterator);
/* Skip the first. We count spans of fence, not fence-posts. */
if (previous == NULL) continue;
if (thd->lex->orig_sql_command == SQLCOM_SHOW_PROFILE)
{
/*
@ -558,29 +565,32 @@ int PROFILING::fill_statistics_info(THD *thd, TABLE_LIST *tables, Item *cond)
table->field[2]->store(previous->status, strlen(previous->status),
system_charset_info);
my_decimal duration;
my_decimal duration_decimal;
double2my_decimal(E_DEC_FATAL_ERROR,
(entry->time_usecs-previous->time_usecs)/(1000.0*1000),
&duration);
table->field[3]->store_decimal(&duration);
&duration_decimal);
table->field[3]->store_decimal(&duration_decimal);
#ifdef HAVE_GETRUSAGE
my_decimal cpu_utime, cpu_stime;
my_decimal cpu_utime_decimal, cpu_stime_decimal;
double2my_decimal(E_DEC_FATAL_ERROR,
RUSAGE_DIFF_USEC(entry->rusage.ru_utime,
previous->rusage.ru_utime) /
(1000.0*1000),
&cpu_utime);
&cpu_utime_decimal);
double2my_decimal(E_DEC_FATAL_ERROR,
RUSAGE_DIFF_USEC(entry->rusage.ru_stime,
previous->rusage.ru_stime) /
(1000.0*1000),
&cpu_stime);
&cpu_stime_decimal);
table->field[4]->store_decimal(&cpu_utime);
table->field[5]->store_decimal(&cpu_stime);
table->field[4]->store_decimal(&cpu_utime_decimal);
table->field[5]->store_decimal(&cpu_stime_decimal);
table->field[4]->set_notnull();
table->field[5]->set_notnull();
#else
@ -639,14 +649,15 @@ int PROFILING::fill_statistics_info(THD *thd, TABLE_LIST *tables, Item *cond)
/* TODO: Add swap info for non-BSD systems */
#endif
if ((entry->function != NULL) && (entry->file != NULL))
/* Emit the location that started this step, not that ended it. */
if ((previous->function != NULL) && (previous->file != NULL))
{
table->field[15]->store(entry->function, strlen(entry->function),
table->field[15]->store(previous->function, strlen(previous->function),
system_charset_info);
table->field[15]->set_notnull();
table->field[16]->store(entry->file, strlen(entry->file), system_charset_info);
table->field[16]->store(previous->file, strlen(previous->file), system_charset_info);
table->field[16]->set_notnull();
table->field[17]->store(entry->line, true);
table->field[17]->store(previous->line, true);
table->field[17]->set_notnull();
}

82
sql/sql_profile.h
View File

@ -54,24 +54,7 @@ int make_profile_table_for_show(THD *thd, ST_SCHEMA_TABLE *schema_table);
#define PROFILE_ALL (~0)
#ifndef ENABLED_PROFILING
# define thd_proc_info(thd, msg) do { (thd)->proc_info= (msg); } while (0)
#else
# define thd_proc_info(thd, msg) \
do { \
if (unlikely(((thd)->options & OPTION_PROFILING) != 0)) \
{ \
(thd)->profiling.status_change((msg), __func__, __FILE__, __LINE__); \
} \
else \
{ \
(thd)->proc_info= (msg); \
} \
} while (0)
#if defined(ENABLED_PROFILING)
#include "mysql_priv.h"
#ifdef HAVE_SYS_RESOURCE_H
@ -79,7 +62,7 @@ int make_profile_table_for_show(THD *thd, ST_SCHEMA_TABLE *schema_table);
#endif
class PROFILE_ENTRY;
class PROF_MEASUREMENT;
class QUERY_PROFILE;
class PROFILING;
@ -193,7 +176,7 @@ public:
/**
A single entry in a single profile.
*/
class PROFILE_ENTRY
class PROF_MEASUREMENT
{
private:
friend class QUERY_PROFILE;
@ -212,22 +195,22 @@ private:
double time_usecs;
char *allocated_status_memory;
void set_status(const char *status_arg, const char *function_arg,
void set_label(const char *status_arg, const char *function_arg,
const char *file_arg, unsigned int line_arg);
void clean_up();
PROFILE_ENTRY();
PROFILE_ENTRY(QUERY_PROFILE *profile_arg, const char *status_arg);
PROFILE_ENTRY(QUERY_PROFILE *profile_arg, const char *status_arg,
PROF_MEASUREMENT();
PROF_MEASUREMENT(QUERY_PROFILE *profile_arg, const char *status_arg);
PROF_MEASUREMENT(QUERY_PROFILE *profile_arg, const char *status_arg,
const char *function_arg,
const char *file_arg, unsigned int line_arg);
~PROFILE_ENTRY();
~PROF_MEASUREMENT();
void collect();
};
/**
The full profile for a single query, and includes multiple PROFILE_ENTRY
The full profile for a single query, and includes multiple PROF_MEASUREMENT
objects.
*/
class QUERY_PROFILE
@ -237,21 +220,21 @@ private:
PROFILING *profiling;
query_id_t server_query_id; /* Global id. */
query_id_t profiling_query_id; /* Session-specific id. */
char *query_source;
PROFILE_ENTRY profile_start;
PROFILE_ENTRY *profile_end;
Queue<PROFILE_ENTRY> entries;
PROF_MEASUREMENT *profile_start;
PROF_MEASUREMENT *profile_end;
Queue<PROF_MEASUREMENT> entries;
QUERY_PROFILE(PROFILING *profiling_arg, char *query_source_arg, uint query_length_arg);
QUERY_PROFILE(PROFILING *profiling_arg, const char *status_arg);
~QUERY_PROFILE();
void set_query_source(char *query_source_arg, uint query_length_arg);
/* Add a profile status change to the current profile. */
void status(const char *status_arg,
void new_status(const char *status_arg,
const char *function_arg,
const char *file_arg, unsigned int line_arg);
@ -269,7 +252,7 @@ private:
class PROFILING
{
private:
friend class PROFILE_ENTRY;
friend class PROF_MEASUREMENT;
friend class QUERY_PROFILE;
/*
@ -291,39 +274,12 @@ public:
~PROFILING();
void set_query_source(char *query_source_arg, uint query_length_arg);
/** Reset the current profile and state of profiling for the next query. */
void reset();
void start_new_query(const char *initial_state= "starting");
/**
Do we intend to keep the currently collected profile?
void discard_current_query();
We don't keep profiles for some commands, such as SHOW PROFILE, SHOW
PROFILES, and some SQLCOM commands which aren't useful to profile. The
keep() and discard() functions can be called many times, only the final
setting when the query finishes is used to decide whether to discard the
profile.
void finish_current_query();
The default is to keep the profile for all queries.
*/
inline void keep() { keeping= true; };
/**
Do we intend to keep the currently collected profile?
@see keep()
*/
inline void discard() { keeping= false; };
/**
Stash this profile in the profile history and remove the oldest
profile if the history queue is full, as defined by the
profiling_history_size system variable.
*/
void store();
/**
Called with every update of the status via thd_proc_info() , and is
therefore the main hook into the profiling code.
*/
void status_change(const char *status_arg,
const char *function_arg,
const char *file_arg, unsigned int line_arg);

21
sql/sql_show.cc
View File

@ -3622,6 +3622,14 @@ ST_SCHEMA_TABLE *get_schema_table(enum enum_schema_tables schema_table_idx)
/*
Create information_schema table using schema_table data
@note
For MYSQL_TYPE_DECIMAL fields only, the field_length member has encoded
into it two numbers, based on modulus of base-10 numbers. In the ones
position is the number of decimals. Tens position is unused. In the
hundreds and thousands position is a two-digit decimal number representing
length. Encode this value with (decimals*100)+length , where
0<decimals<10 and 0<=length<100 .
SYNOPSIS
create_schema_table()
thd thread handler
@ -3667,6 +3675,19 @@ TABLE *create_schema_table(THD *thd, TABLE_LIST *table_list)
DBUG_RETURN(NULL);
break;
case MYSQL_TYPE_DECIMAL:
if (!(item= new Item_decimal((longlong) fields_info->value, false)))
{
DBUG_RETURN(0);
}
item->decimals= fields_info->field_length%10;
item->max_length= (fields_info->field_length/100)%100;
if (item->unsigned_flag == 0)
item->max_length+= 1;
if (item->decimals > 0)
item->max_length+= 1;
item->set_name(fields_info->field_name,
strlen(fields_info->field_name), cs);
break;
case MYSQL_TYPE_STRING:
default:
/* Don't let unimplemented types pass through. Could be a grave error. */