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

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

Backport from 5.1 .


include/my_sys.h:
  Prepare for rename in 5.1.
mysql-test/r/profiling.result:
  Backport tests from 5.1.
mysql-test/t/profiling.test:
  Backport tests from 5.1.
sql/mysql_priv.h:
  Backport changes from 5.1 .
sql/sp_head.cc:
  Backport changes from 5.1 .
sql/sql_class.cc:
  Backport changes from 5.1 .
sql/sql_parse.cc:
  Backport changes from 5.1 .
sql/sql_profile.cc:
  Push history-limiting code until after the code that adds new 
  history entries.  Lazy deletion isn't smart or useful here.
  
  Correct for 5.0 member existance and execution.
sql/sql_profile.h:
  Backport changes from 5.1 .
sql/sql_show.cc:
  Backport changes from 5.1 .

7 files changed, 348 insertions, 279 deletions

diff --git a/sql/mysql_priv.h b/sql/mysql_priv.h
index 3482cfe9a70..20e4dacaded 100644
--- a/sql/mysql_priv.h
+++ b/sql/mysql_priv.h
@@ -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))
 
diff --git a/sql/sp_head.cc b/sql/sp_head.cc
index c659b222628..2c02b07206f 100644
--- a/sql/sp_head.cc
+++ b/sql/sp_head.cc
@@ -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)))
   {
diff --git a/sql/sql_class.cc b/sql/sql_class.cc
index ebce723d577..a8725923624 100644
--- a/sql/sql_class.cc
+++ b/sql/sql_class.cc
@@ -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()
diff --git a/sql/sql_parse.cc b/sql/sql_parse.cc
index 7e105689d22..e3166c07cbd 100644
--- a/sql/sql_parse.cc
+++ b/sql/sql_parse.cc
@@ -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;
 }
diff --git a/sql/sql_profile.cc b/sql/sql_profile.cc
index 30bedcfc813..6ae70ab1d13 100644
--- a/sql/sql_profile.cc
+++ b/sql/sql_profile.cc
@@ -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>";
@@ -28,25 +44,26 @@ const char * const _unknown_func_ = "<unknown>";
 /**
   Connects Information_Schema and Profiling.
 */
-int fill_query_profile_statistics_info(THD *thd, TABLE_LIST *tables, 
+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;
@@ -162,7 +175,7 @@ void PROFILE_ENTRY::set_status(const char *status_arg, const char *function_arg,
   sizes[0]= (status_arg == NULL) ? 0 : strlen(status_arg) + 1;
   sizes[1]= (function_arg == NULL) ? 0 : strlen(function_arg) + 1;
   sizes[2]= (file_arg == NULL) ? 0 : strlen(file_arg) + 1;
-    
+
   allocated_status_memory= (char *) my_malloc(sizes[0] + sizes[1] + sizes[2], MYF(0));
   DBUG_ASSERT(allocated_status_memory != NULL);
 
@@ -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)
-{
-  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)
+QUERY_PROFILE::QUERY_PROFILE(PROFILING *profiling_arg, const char *status_arg)
+  :profiling(profiling_arg), profiling_query_id(0), query_source(NULL)
 {
-  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)
+{
+  /* 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)
 {
-  THD *thd= profiling->thd;
-  PROFILE_ENTRY *prof;
+  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;
-  }
+  if ((function_arg != NULL) && (file_arg != NULL))
+    prof= new PROF_MEASUREMENT(this, status_arg, function_arg, file_arg, line_arg);
+  else
+    prof= new PROF_MEASUREMENT(this, status_arg);
 
-  /* 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);
-  } 
-  else 
-  {
-    if ((profile_end= prof= new PROFILE_ENTRY(this, status_arg)))
-      entries.push_back(prof);
-  }
+  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,95 +295,110 @@ 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 (unlikely(enabled))
-  {
-    if (unlikely(current == NULL))
-      reset();
 
-    DBUG_ASSERT(current != NULL);
+  if (status_arg == NULL)  /* We don't know how to handle that */
+    DBUG_VOID_RETURN;
 
-    current->status(status_arg, function_arg, file_arg, line_arg);
-  }
+  if (current == NULL)  /* This profile was already discarded. */
+    DBUG_VOID_RETURN;
+
+  if (unlikely(enabled))
+    current->new_status(status_arg, function_arg, file_arg, line_arg);
 
-  thd->proc_info= status_arg;
   DBUG_VOID_RETURN;
 }
 
-void 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.
+
+  @param  initial_state  (optional) name of period before first state change
+*/
+void PROFILING::start_new_query(const char *initial_state)
 {
-  DBUG_ENTER("PROFILING::store");
+  DBUG_ENTER("PROFILING::start_new_query");
 
-  /* Already stored */
-  if (unlikely((last != NULL) && 
-               (current != NULL) && 
-               (last->server_query_id == current->server_query_id)))
+  /* 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? */
-        (current->query_source != NULL) && 
-        (current->query_source[0] != '\0') && 
-        (!current->entries.is_empty())) 
+    /* 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->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
     {
       delete current;
       current= NULL;
     }
   }
-  
-  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;
 }
@@ -410,29 +414,29 @@ bool PROFILING::show_profiles()
   field_list.push_back(new Item_return_int("Duration", TIME_FLOAT_DIGITS-1,
                                            MYSQL_TYPE_DOUBLE));
   field_list.push_back(new Item_empty_string("Query", 40));
-                                           
+
   if (thd->protocol->send_fields(&field_list,
                                  Protocol::SEND_NUM_ROWS | Protocol::SEND_EOF))
     DBUG_RETURN(TRUE);
-    
+
   SELECT_LEX *sel= &thd->lex->select_lex;
   SELECT_LEX_UNIT *unit= &thd->lex->unit;
   ha_rows idx= 0;
   Protocol *protocol= thd->protocol;
 
   unit->set_limit(sel);
-  
+
   void *iterator;
-  for (iterator= history.new_iterator(); 
-       iterator != NULL; 
+  for (iterator= history.new_iterator();
+       iterator != NULL;
        iterator= history.iterator_next(iterator))
   {
     prof= history.iterator_value(iterator);
 
     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;
@@ -441,14 +445,14 @@ bool PROFILING::show_profiles()
 
     protocol->prepare_for_resend();
     protocol->store((uint32)(prof->profiling_query_id));
-    protocol->store((double)(pe->time_usecs - ps->time_usecs)/(1000.0*1000), 
+    protocol->store((double)(pe->time_usecs - ps->time_usecs)/(1000.0*1000),
                     (uint32) TIME_FLOAT_DIGITS-1, &elapsed);
     if (prof->query_source != NULL)
-      protocol->store(prof->query_source, strlen(prof->query_source), 
+      protocol->store(prof->query_source, strlen(prof->query_source),
                       system_charset_info);
     else
       protocol->store_null();
-    
+
     if (protocol->write())
       DBUG_RETURN(TRUE);
   }
@@ -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,11 +480,10 @@ 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
-  schema, and a SHOW command.  
+  schema, and a SHOW command.
 */
 int PROFILING::fill_statistics_info(THD *thd, TABLE_LIST *tables, Item *cond)
 {
@@ -489,12 +494,11 @@ int PROFILING::fill_statistics_info(THD *thd, TABLE_LIST *tables, Item *cond)
   QUERY_PROFILE *query;
   /* Go through each query in this thread's stored history... */
   void *history_iterator;
-  for (history_iterator= history.new_iterator(); 
-       history_iterator != NULL; 
+  for (history_iterator= history.new_iterator();
+       history_iterator != NULL;
        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,18 +508,21 @@ 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; 
+    for (seq= 0, entry_iterator= query->entries.new_iterator();
+         entry_iterator != NULL;
          entry_iterator= query->entries.iterator_next(entry_iterator),
          seq++, previous=entry, row_number++)
     {
       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)
       {
-        /* 
+        /*
           We got here via a SHOW command.  That means that we stored
           information about the query we wish to show and that isn't
           in a WHERE clause at a higher level to filter out rows we
@@ -555,43 +562,46 @@ int PROFILING::fill_statistics_info(THD *thd, TABLE_LIST *tables, Item *cond)
         time that a status phrase took T(n)-T(n-1), this line must describe the
         previous status.
       */
-      table->field[2]->store(previous->status, strlen(previous->status), 
+      table->field[2]->store(previous->status, strlen(previous->status),
                              system_charset_info);
 
-      my_decimal duration;
-      double2my_decimal(E_DEC_FATAL_ERROR, 
+      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;
-      double2my_decimal(E_DEC_FATAL_ERROR, 
-                        RUSAGE_DIFF_USEC(entry->rusage.ru_utime, 
+      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, 
+      double2my_decimal(E_DEC_FATAL_ERROR,
                         RUSAGE_DIFF_USEC(entry->rusage.ru_stime,
-                                         previous->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
       /* TODO: Add CPU-usage info for non-BSD systems */
 #endif
-      
+
 #ifdef HAVE_GETRUSAGE
-      table->field[6]->store((uint32)(entry->rusage.ru_nvcsw - 
+      table->field[6]->store((uint32)(entry->rusage.ru_nvcsw -
                              previous->rusage.ru_nvcsw));
       table->field[6]->set_notnull();
-      table->field[7]->store((uint32)(entry->rusage.ru_nivcsw - 
+      table->field[7]->store((uint32)(entry->rusage.ru_nivcsw -
                              previous->rusage.ru_nivcsw));
       table->field[7]->set_notnull();
 #else
@@ -599,32 +609,32 @@ int PROFILING::fill_statistics_info(THD *thd, TABLE_LIST *tables, Item *cond)
 #endif
 
 #ifdef HAVE_GETRUSAGE
-      table->field[8]->store((uint32)(entry->rusage.ru_inblock - 
+      table->field[8]->store((uint32)(entry->rusage.ru_inblock -
                              previous->rusage.ru_inblock));
       table->field[8]->set_notnull();
-      table->field[9]->store((uint32)(entry->rusage.ru_oublock - 
+      table->field[9]->store((uint32)(entry->rusage.ru_oublock -
                              previous->rusage.ru_oublock));
       table->field[9]->set_notnull();
 #else
       /* TODO: Add block IO info for non-BSD systems */
 #endif
-    
+
 #ifdef HAVE_GETRUSAGE
-      table->field[10]->store((uint32)(entry->rusage.ru_msgsnd - 
+      table->field[10]->store((uint32)(entry->rusage.ru_msgsnd -
                              previous->rusage.ru_msgsnd), true);
       table->field[10]->set_notnull();
-      table->field[11]->store((uint32)(entry->rusage.ru_msgrcv - 
+      table->field[11]->store((uint32)(entry->rusage.ru_msgrcv -
                              previous->rusage.ru_msgrcv), true);
       table->field[11]->set_notnull();
 #else
       /* TODO: Add message info for non-BSD systems */
 #endif
-    
+
 #ifdef HAVE_GETRUSAGE
-      table->field[12]->store((uint32)(entry->rusage.ru_majflt - 
+      table->field[12]->store((uint32)(entry->rusage.ru_majflt -
                              previous->rusage.ru_majflt), true);
       table->field[12]->set_notnull();
-      table->field[13]->store((uint32)(entry->rusage.ru_minflt - 
+      table->field[13]->store((uint32)(entry->rusage.ru_minflt -
                              previous->rusage.ru_minflt), true);
       table->field[13]->set_notnull();
 #else
@@ -632,21 +642,22 @@ int PROFILING::fill_statistics_info(THD *thd, TABLE_LIST *tables, Item *cond)
 #endif
 
 #ifdef HAVE_GETRUSAGE
-      table->field[14]->store((uint32)(entry->rusage.ru_nswap - 
+      table->field[14]->store((uint32)(entry->rusage.ru_nswap -
                              previous->rusage.ru_nswap), true);
       table->field[14]->set_notnull();
 #else
       /* 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),
-                        system_charset_info);        
+        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();
       }
 
diff --git a/sql/sql_profile.h b/sql/sql_profile.h
index 5a28bc32442..022422fbb81 100644
--- a/sql/sql_profile.h
+++ b/sql/sql_profile.h
@@ -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();
-
-  /**
-    Do we intend to keep the currently collected profile?
-    
-    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.
-    
-    The default is to keep the profile for all queries.
-  */
-  inline void keep()    { keeping= true; };
+  void start_new_query(const char *initial_state= "starting");
 
-  /**
-    Do we intend to keep the currently collected profile?
-    @see keep()
-  */
-  inline void discard() { keeping= false; };
+  void discard_current_query();
 
-  /** 
-    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();
+  void finish_current_query();
 
-  /**
-    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);
diff --git a/sql/sql_show.cc b/sql/sql_show.cc
index cd5b537996d..1eb6838d98e 100644
--- a/sql/sql_show.cc
+++ b/sql/sql_show.cc
@@ -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. */