List:Internals« Previous MessageNext Message »
From:Rick James Date:August 6 2007 10:00pm
Subject:RE: sql_log_slow and executable comment version fun.
View as plain text  
As long as we are talking about wish lists...  Plz include slow queries from
the replication stream -- at least optionally. 

> -----Original Message-----
> From: Chad MILLER [mailto:cmiller@stripped] 
> Sent: Monday, July 30, 2007 12:10 PM
> To: Eric Bergen
> Cc: internals@stripped
> Subject: Re: sql_log_slow and executable comment version fun.
> 
> Hi Eric.  Sorry for the delay.
> 
> On 19 Jul 2007, at 00:48, Eric Bergen wrote:
> 
> > The slow query log is a great tool for finding long running queries.
> > One thing it doesn't do is allow you to not log known slow queries.
> > Slow queries from things like importing large sql files. With
> > long_query_time set low enough bulk insert queries from 
> dump files are
> > also written out to the slow query log. The entire query is 
> written to
> > the log. On a large dump file the log can quickly grow to gigs in
> > size.
> >
> > This patch serves two purposes. First it adds a variable to 
> mysql that
> > works exactly like sql_log_bIn in that it allows clients to prevent
> > queries from being logged at the session level. Second it updates
> > mysqldump to add this variable to it's dump output.
> 
> I agree it could be better, and I like the general idea.  Do you  
> really need a new variable?  Could a session-level 
> (long_query_time =  
> 0 and log_queries_not_using_indexes = FALSE) do the same thing?
> 
> In any case, I'll add a few minor notes to the patch, included below.
> 
> > A possible side effect of this new variable output is that 
> it's tagged
> > with a version number. In the old days this would be fine 
> since newer
> > versions of mysql will know about the variable and act accordingly.
> > However, with mysql enterprise it's possible that newer versions of
> > enterprise will have a higher version number than what's in 
> output of
> > mysql yet not support the new variable. Importing a dump 
> file created
> > on a version of mysql with this patch then trying to import it on a
> > newer version without the patch will error. What are the lists
> > thoughts on how to handle this?
> 
> Good catch.  One way we're avoiding this problem is by adding 
> all new  
> features into the alpha (or development) tree as normal.  With this  
> feature as an example, if it were ready now, it would go into 5.2.
> 
> - chad
> 
> 
> > diff -aur mysql-5.0.41-orig/client/mysqldump.c mysql-5.0.41/client/ 
> > mysqldump.c
> > --- mysql-5.0.41-orig/client/mysqldump.c	2007-06-24  
> > 19:58:29.000000000 -0700
> > +++ mysql-5.0.41/client/mysqldump.c	2007-06-24 19:58:48.000000000  
> > -0700
> > @@ -579,6 +579,7 @@
> >  ");
> >      }
> >      fprintf(sql_file,
> > +            "/*!50041 SET @SQL_LOG_SLOW=0 */;\n"
> >              "/*!40101 SET @OLD_SQL_MODE=@@SQL_MODE, 
> SQL_MODE='%s%s% 
> > s' */;\n"
> >              "/*!40111 SET @OLD_SQL_NOTES=@@SQL_NOTES, SQL_NOTES=0  
> > */;\n",
> >               
> > path?"":"NO_AUTO_VALUE_ON_ZERO",compatible_mode_normal_str[0] 
> > ==0?"":",",
> > diff -aur mysql-5.0.41-orig/sql/mysql_priv.h mysql-5.0.41/sql/ 
> > mysql_priv.h
> > --- mysql-5.0.41-orig/sql/mysql_priv.h	2007-06-24  
> > 19:58:29.000000000 -0700
> > +++ mysql-5.0.41/sql/mysql_priv.h	2007-06-24 
> 20:31:40.000000000 -0700
> > @@ -344,6 +344,7 @@
> >  #define OPTION_TABLE_LOCK       (ULL(1) << 21)    // THD, intern
> >  #define OPTION_QUICK            (ULL(1) << 22)    // SELECT (for  
> > DELETE)
> >  #define OPTION_QUOTE_SHOW_CREATE (ULL(1) << 23)   // THD, user
> > +#define OPTION_LOG_SLOW          (ULL(1) << 23)   // THD, user
> 
> (ITYM "24".)
> 
> >
> >  /* Thr following is used to detect a conflict with DISTINCT
> >     in the user query has requested */
> > diff -aur mysql-5.0.41-orig/sql/set_var.cc 
> mysql-5.0.41/sql/set_var.cc
> > --- mysql-5.0.41-orig/sql/set_var.cc	2007-06-24 
> 19:58:29.000000000  
> > -0700
> > +++ mysql-5.0.41/sql/set_var.cc	2007-06-24 
> 20:28:11.000000000 -0700
> > @@ -95,6 +95,7 @@
> >  static bool set_log_update(THD *thd, set_var *var);
> >  static int  check_pseudo_thread_id(THD *thd, set_var *var);
> >  static bool set_log_bin(THD *thd, set_var *var);
> > +static bool set_log_slow(THD *thd, set_var *var);
> >  static void fix_low_priority_updates(THD *thd, enum_var_type type);
> >  static void fix_tx_isolation(THD *thd, enum_var_type type);
> >  static int check_completion_type(THD *thd, set_var *var);
> > @@ -518,6 +519,10 @@
> >                                         check_log_update,
> >  				       set_log_bin,
> >  				       OPTION_BIN_LOG);
> > +static sys_var_thd_bit  sys_log_slowlog("sql_log_slow",
> > +                                       check_log_update,
> > +                                       set_log_slow,
> > +                                       OPTION_LOG_SLOW);
> >  static sys_var_thd_bit	sys_sql_warnings("sql_warnings", 0,
> >  					 set_option_bit,
> >  					 OPTION_WARNINGS);
> > @@ -667,6 +672,7 @@
> >    &sys_log_binlog,
> >    &sys_log_off,
> >    &sys_log_queries_not_using_indexes,
> > +  &sys_log_slowlog,
> >    &sys_log_update,
> >    &sys_log_warnings,
> >    &sys_long_query_time,
> > @@ -2946,6 +2952,19 @@
> >    return 0;
> >  }
> >
> > +static bool set_log_slow(THD *thd, set_var *var)
> > +{
> > +  DBUG_PRINT("info", ("Setting sql_log_slow to (%d)", 
> opt_slow_log));
> > +  if (opt_slow_log)
> > +  {
> > +      DBUG_PRINT("info", ("opt_slow_log detected doing or of (%d) 
> > \n", OPTION_LOG_SLOW));
> > +    ((sys_var_thd_bit*) var->var)->bit_flag|= OPTION_LOG_SLOW;
> > +  }
> 
> That's awkward phrasing in the DBUG_PRINT.
> 
> (And the indentation is weird in the assignment.)
> 
> > +
> > +  set_option_bit(thd, var);
> > +  return 0;
> > +}
> > +
> >  static int check_pseudo_thread_id(THD *thd, set_var *var)
> >  {
> >    var->save_result.ulonglong_value= var->value->val_int();
> > diff -aur mysql-5.0.41-orig/sql/sql_parse.cc mysql-5.0.41/sql/ 
> > sql_parse.cc
> > --- mysql-5.0.41-orig/sql/sql_parse.cc	2007-06-24  
> > 19:58:29.000000000 -0700
> > +++ mysql-5.0.41/sql/sql_parse.cc	2007-06-24 
> 20:33:27.000000000 -0700
> > @@ -2178,6 +2178,12 @@
> >    start_of_query= thd->start_time;
> >    thd->end_time();				// Set start time
> >
> > +  if ((thd->options & OPTION_LOG_SLOW) == 0)
> > +  {
> > +    DBUG_PRINT("info", ("Found slow option not set, returning\n"));
> > +    return;
> > +  }
> > +
> >    /*
> >      Do not log administrative statements unless the appropriate  
> > option is
> >      set; do not log into slow log if reading from backup.
> 
> You're missing tests.  I bet this changes the output of some tests,  
> also.
> 
> - chad
> 
> --
> Chad Miller, Software Developer                         chad@stripped
> MySQL Inc., www.mysql.com
> Orlando, Florida, USA                                13-20z,  UTC-0400
> Office: +1 408 213 6740                         sip:6740@stripped
> 
> 
> 

Thread
sql_log_slow and executable comment version fun.Eric Bergen19 Jul
  • RE: sql_log_slow and executable comment version fun.Rick James20 Jul
    • Re: sql_log_slow and executable comment version fun.Eric Bergen29 Jul
  • Re: sql_log_slow and executable comment version fun.Chad MILLER30 Jul
    • RE: sql_log_slow and executable comment version fun.Rick James7 Aug
      • Re: sql_log_slow and executable comment version fun.Eric Bergen22 Aug