Branch location changed to: lp:~daniel-nichter/drizzle/query-log-plugin

Le 15 mai 2011 à 12:13, Daniel Nichter a écrit :

> Daniel Nichter has proposed merging lp:~daniel-percona/drizzle/query-log-plugin into lp:drizzle.
> 
> Requested reviews:
>  Drizzle Merge Team (drizzle-merge)
> Related bugs:
>  Bug #781971 in Drizzle: "Write new query log plugin"
>  https://bugs.launchpad.net/drizzle/+bug/781971
> 
> For more details, see:
> https://code.launchpad.net/~daniel-percona/drizzle/query-log-plugin/+merge/61034
> 
> I think this plugin can and should replace logging_query.  :-)  The major parts are tested and it's documented.  If merged, I'll continue to maintain and enhance it.
> -- 
> https://code.launchpad.net/~daniel-percona/drizzle/query-log-plugin/+merge/61034
> You are the owner of lp:~daniel-percona/drizzle/query-log-plugin.
> === added directory 'plugin/query_log'
> === added file 'plugin/query_log/event.h'
> --- plugin/query_log/event.h	1970-01-01 00:00:00 +0000
> +++ plugin/query_log/event.h	2011-05-15 18:13:26 +0000
> @@ -0,0 +1,66 @@
> +/*
> +  *  Copyright (C) 2011 Daniel Nichter
> + *
> + *  This program is free software; you can redistribute it and/or modify
> + *  it under the terms of the GNU General Public License as published by
> + *  the Free Software Foundation; version 2 of the License.
> + *
> + *  This program is distributed in the hope that it will be useful,
> + *  but WITHOUT ANY WARRANTY; without even the implied warranty of
> + *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
> + *  GNU General Public License for more details.
> + *
> + *  You should have received a copy of the GNU General Public License
> + *  along with this program; if not, write to the Free Software
> + *  Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA  02110-1301  USA
> + */
> +
> +#pragma once
> +
> +/**
> + * @file
> + *   event.h
> + *
> + * @brief
> + *   Defines the event_t struct that encapsulates an event.
> + *
> + * @details
> + *   An event (i.e. a query) has the attributes defined in the event_t struct.
> + *   The values come from various members of the Session class.  This is
> + *   a necessary redundancy for two reasons.  First, access to this data via
> + *   the Session class is not uniform; it requires various calls and
> + *   calculations.  Look at QueryLog::afterStatement() to see this.  Second,
> + *   because the QueryLog object controls the logger classes, i.e.
> + *   QueryLoggerFile and others in the futre, event creation and filtering
> + *   is done in one place (QueryLog::afterStatement()) and then acceptable
> + *   events are passed to the logger classes so that all they have to do is log.
> + *
> + *   Since this is just a collection of variables, making this a class
> + *   with accessor functions is overkill.
> + */
> +struct event_t {
> +  // GMT timestamps (2002-01-31T10:00:01.123456)
> +  std::string ts;
> +
> +  // integers
> +  uint32_t session_id;
> +  uint32_t query_id;
> +  uint32_t rows_examined;
> +  uint32_t rows_sent;
> +  uint32_t tmp_tables;
> +  uint32_t warnings;
> +
> +  // times (42.123456)
> +  double execution_time;
> +  double lock_time;
> +  double session_time;
> +
> +  // bools ("true" or "false")
> +  const char *error;
> +
> +  // strings, not quoted or escaped
> +  const char *schema;
> +
> +  // query, not quoted or escaped
> +  const char *query;
> +};
> 
> === added file 'plugin/query_log/file.cc'
> --- plugin/query_log/file.cc	1970-01-01 00:00:00 +0000
> +++ plugin/query_log/file.cc	2011-05-15 18:13:26 +0000
> @@ -0,0 +1,96 @@
> +/* -*- mode: c++; c-basic-offset: 2; indent-tabs-mode: nil; -*-
> + *  vim:expandtab:shiftwidth=2:tabstop=2:smarttab:
> + *
> + *  Copyright (C) 2011 Daniel Nichter
> + *
> + *  This program is free software; you can redistribute it and/or modify
> + *  it under the terms of the GNU General Public License as published by
> + *  the Free Software Foundation; version 2 of the License.
> + *
> + *  This program is distributed in the hope that it will be useful,
> + *  but WITHOUT ANY WARRANTY; without even the implied warranty of
> + *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
> + *  GNU General Public License for more details.
> + *
> + *  You should have received a copy of the GNU General Public License
> + *  along with this program; if not, write to the Free Software
> + *  Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA  02110-1301  USA
> + */
> +
> +#include <config.h>
> +#include <string>
> +#include <fcntl.h>
> +#include "file.h"
> +
> +using namespace std;
> +
> +QueryLoggerFile::QueryLoggerFile()
> +{
> +  _fd= LOG_FILE_CLOSED;
> +
> +  // If you add something here, the number of params must match the number
> +  // of values pushed to the formatter in logEvent().
> +  _formatter.parse(
> +    "# %s\n"
> +    "# session_id=%d query_id=%d rows_examined=%d rows_sent=%d tmp_tables=%d warnings=%d\n"
> +    "# execution_time=%.6f lock_time=%.6f session_time=%.6f\n"
> +    "# error=%s\n"
> +    "# schema=\"%s\"\n"
> +    "%s;\n#\n"
> +  );
> +}
> +
> +QueryLoggerFile::~QueryLoggerFile()
> +{
> +  closeLogFile();
> +}
> +
> +bool QueryLoggerFile::logEvent(const event_t *event)
> +{
> +  if (_fd == LOG_FILE_CLOSED)
> +    return false;
> +
> +  _formatter
> +    % event->ts
> +    % event->session_id
> +    % event->query_id
> +    % event->rows_examined
> +    % event->rows_sent
> +    % event->tmp_tables
> +    % event->warnings
> +    % event->execution_time
> +    % event->lock_time  // broken
> +    % event->session_time
> +    % event->error
> +    % event->schema
> +    % event->query;
> +  string msgbuf= _formatter.str();
> +
> +  size_t wrv;
> +  wrv= write(_fd, msgbuf.c_str(), msgbuf.length());
> +  assert(wrv == msgbuf.length());
> +
> +  return false; // success
> +}
> +
> +bool QueryLoggerFile::openLogFile(const char *file)
> +{
> +  assert(file != NULL);
> + 
> +  int new_fd= open(file, O_WRONLY | O_APPEND | O_CREAT, S_IRUSR | S_IWUSR);
> +  if (new_fd < 0)
> +    return true; // error
> +
> +  closeLogFile();
> +  _fd= new_fd;
> +
> +  return false; // success
> +}
> +
> +bool QueryLoggerFile::closeLogFile()
> +{
> +  if (not _fd == LOG_FILE_CLOSED)
> +    close(_fd);  // TODO: catch errors
> +  _fd= LOG_FILE_CLOSED;
> +  return false;  // success
> +}
> 
> === added file 'plugin/query_log/file.h'
> --- plugin/query_log/file.h	1970-01-01 00:00:00 +0000
> +++ plugin/query_log/file.h	2011-05-15 18:13:26 +0000
> @@ -0,0 +1,89 @@
> +/*
> +  *  Copyright (C) 2011 Daniel Nichter
> + *
> + *  This program is free software; you can redistribute it and/or modify
> + *  it under the terms of the GNU General Public License as published by
> + *  the Free Software Foundation; version 2 of the License.
> + *
> + *  This program is distributed in the hope that it will be useful,
> + *  but WITHOUT ANY WARRANTY; without even the implied warranty of
> + *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
> + *  GNU General Public License for more details.
> + *
> + *  You should have received a copy of the GNU General Public License
> + *  along with this program; if not, write to the Free Software
> + *  Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA  02110-1301  USA
> + */
> +
> +#include <boost/format.hpp>
> +#include "event.h"
> +
> +#define LOG_FILE_CLOSED -1
> +
> +/**
> + * @brief
> + *   QueryLoggerFile implements logging to a file for the QueryLog class.
> + *
> + * @details
> + *   This class is not a plugin (class QueryLog is the plugin class), it is
> + *   a utility class used by the QueryLog class to do the actual logging to
> + *   the query log file.  QueryLog deals with Drizzle; this class deals with
> + *   formatting the event and writing it to the log file.
> + */
> +class QueryLoggerFile
> +{
> +public:
> +  QueryLoggerFile();
> +  ~QueryLoggerFile();
> +
> +  /**
> +   * @brief
> +   *   Format and write the event to the log file.
> +   *
> +   * @details
> +   *   This function is called by QueryLog::afterStatement().  The given
> +   *   event is a uniform struct (see event.h) and has passed filtering
> +   *   (thresholds, etc.), so it's ready to log.
> +   *
> +   * @param[in] event Event to log
> +   *
> +   * @retval true  Error, event not logged
> +   * @retval false Success, event logged
> +   */
> +  bool logEvent(const event_t *event);
> +
> +  /**
> +   * @brief
> +   *   Open new log file, close old log file if successful.
> +   *
> +   * @details
> +   *   When global system variable query_log_file is changed, update_file()
> +   *   in module.cc is called which calls this function, passing it the new
> +   *   log file name.  If opening the new log file succeeds, then the old log
> +   *   file is closed, else the old log if kept, and error is printed and
> +   *   query_log_file is not changed.
> +   *
> +   * @param[in] file New log file name to open
> +   *
> +   * @retval true  Error, new log file not opened, old log file still open
> +   * @retval false Success, old log file closed, new log file opened
> +   */
> +  bool openLogFile(const char *file);
> +
> +  /**
> +   * @brief
> +   *   Close the log file.
> +   *
> +   * @details
> +   *   If query_log_file_enabled is false, then the log file is closed.
> +   *   However, the log file is not closed if query_log_enabled is false.
> +   *
> +   * @retval true  Error, log file may not be closed
> +   * @retval false Success, log file closed
> +   */
> +  bool closeLogFile();
> +
> +private:
> +  int _fd;                   ///< File descriptor for open log file
> +  boost::format _formatter;  ///< Log file format printer
> +};
> 
> === added file 'plugin/query_log/module.cc'
> --- plugin/query_log/module.cc	1970-01-01 00:00:00 +0000
> +++ plugin/query_log/module.cc	2011-05-15 18:13:26 +0000
> @@ -0,0 +1,276 @@
> +/* -*- mode: c++; c-basic-offset: 2; indent-tabs-mode: nil; -*-
> + *  vim:expandtab:shiftwidth=2:tabstop=2:smarttab:
> + *
> + *  Copyright (C) 2011 Daniel Nichter
> + *
> + *  This program is free software; you can redistribute it and/or modify
> + *  it under the terms of the GNU General Public License as published by
> + *  the Free Software Foundation; version 2 of the License.
> + *
> + *  This program is distributed in the hope that it will be useful,
> + *  but WITHOUT ANY WARRANTY; without even the implied warranty of
> + *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
> + *  GNU General Public License for more details.
> + *
> + *  You should have received a copy of the GNU General Public License
> + *  along with this program; if not, write to the Free Software
> + *  Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA  02110-1301  USA
> + */
> +
> +#include <config.h>
> +#include <string>
> +#include <boost/program_options.hpp>
> +#include <drizzled/item.h>
> +#include <drizzled/data_home.h>
> +#include <drizzled/module/option_map.h>
> +#include <drizzled/session.h>
> +#include <drizzled/plugin.h>
> +#include "query_log.h"
> +
> +namespace po= boost::program_options;
> +using namespace std;
> +using namespace drizzled;
> +
> +namespace drizzle_plugin
> +{
> +
> +/**
> + * An instance of our class, QueryLog, which implements the query_log plugin,
> + * and an instance of the QueryLoggerClass for logging queries to a file.
> + * These objects are global so update_file() and update_file_enabled() can
> + * access them.  They're instantiated in init_options().
> + */
> +static drizzled::plugin::QueryLog *query_log= NULL;
> +static QueryLoggerFile *logger_file= NULL;
> +
> +/**
> + * Sensible defaults.
> + */
> +const char *default_file= "drizzled-queries.log"; ///< Default query log file
> +
> +/**
> + * @brief
> + *   Update query_log_file (query_log->sysvar_file).
> + *
> + * @details
> + *   When SET GLOBAL query_log_file="new-file.log" is executed by the user,
> + *   this function is called which checkes that the new file is not NULL or
> + *   a blank string, then calls logger_file->openLogFile, passing it the new
> + *   log file name, e.g. "new-file.log".  If the new log file is opened, the
> + *   system variable is updated, else it is not updated and logging continues
> + *   to the old log file.
> + *
> + * @retval true  Error, log file not changed
> + * @retval false Success, log file changed
> + */  
> +bool update_file(Session *, set_var *var)
> +{
> +  const char *new_file= var->value->str_value.ptr();
> +
> +  if (!new_file)
> +  {
> +    errmsg_printf(error::ERROR, _("The query log file name must be defined."));
> +    return false;
> +  }
> +
> +  if (strlen(new_file) == 0)
> +  {
> +    errmsg_printf(error::ERROR, _("The query log file name must have a value."));
> +    return false;
> +  }
> +
> +  /**
> +   * If the the log file is enabled, then try to open the new log file.
> +   * If it's not enabled, then just update query_log_file because the user
> +   * might be trying to:
> +   *   close current log file (SET GLOBAL log_file_enabled=FALSE)
> +   *   switch to new log file (SET GLOBAL log_file="new-file.log")
> +   *   enable new log file (SET GLOBAL log_file_enabled=TRUE)
> +   * (Maybe they're doing this to rotate the log?)  If this is the case,
> +   * then we don't want to open the new log file before it's enabled,
> +   * but we also don't want to leave query_log_file set to the old log
> +   * file name.  When the log file is re-enabled later, update_file_enabled()
> +   * will be called and the new log file will be opened.
> +   */
> +  if (query_log->sysvar_file_enabled)
> +  {
> +    if (logger_file->openLogFile(new_file))
> +    {
> +      errmsg_printf(error::ERROR, "Cannot open the query log file %s", new_file);
> +      return true; // error
> +    }
> +  }
> +
> +  // Update query_log_file in SHOW VARIABLES.
> +  query_log->sysvar_file= new_file;
> +
> +  return false;  // success
> +}
> +
> +/**
> + * @brief
> + *   Update query_log_file_enabled (query_log->sysvar_file_enabled).
> + *
> + * @details
> + *   When SET GLOBAL query_log_file_enabled=... is executed by the user,
> + *   this function is called *after* Drizzle updates the variable with the
> + *   new value, so in this function we have the new/current value.  If the
> + *   log file is enabled, then open query_log_file (query_log->sysvar_file);
> + *   else, close the log file.
> + */  
> +void update_file_enabled(Session *, sql_var_t)
> +{
> +  if (query_log->sysvar_file_enabled)
> +  {
> +    if (logger_file->openLogFile(query_log->sysvar_file.c_str()))
> +    {
> +      errmsg_printf(error::ERROR, "Cannot enable the query log file because the query log file %s cannot be opened.", query_log->sysvar_file.c_str());
> +      query_log->sysvar_file_enabled= false;
> +    }
> +  }
> +  else
> +    logger_file->closeLogFile();
> +}
> +
> +/**
> + * @brief
> + *   Initialize query-log command line options.
> + *
> + * @details
> + *   This function is called first, before init().  We instantiate our one
> + *   and only QueryLog object (query_log) here so that po (boost::program_options)
> + *   can store the command line options' values in public query_log variables.
> + *   This avoids using global variables and keeps (almost) everything encapsulated
> + *   in query_log.
> + */
> +static void init_options(drizzled::module::option_context &context)
> +{
> +  logger_file= new QueryLoggerFile();
> +  query_log= new drizzled::plugin::QueryLog(true, logger_file);
> +
> +  context(
> +    "file-enabled",
> +    po::value<bool>(&query_log->sysvar_file_enabled)->default_value(false)->zero_tokens(),
> +    N_("Enable query logging to file"));
> +
> +  context(
> +    "file",
> +    po::value<string>(&query_log->sysvar_file)->default_value(default_file),
> +    N_("Query log file"));
> +
> +  context(
> +    "threshold-execution-time",
> +    po::value<uint32_constraint>(&query_log->sysvar_threshold_execution_time)->default_value(0),
> +    _("Threshold for logging slow queries, in microseconds"));
> +  
> +  context(
> +    "threshold-lock-time",
> +    po::value<uint32_constraint>(&query_log->sysvar_threshold_lock_time)->default_value(0),
> +    _("Threshold for logging long locking queries, in microseconds"));
> +  
> +  context(
> +    "threshold-rows-examined",
> +    po::value<uint32_constraint>(&query_log->sysvar_threshold_rows_examined)->default_value(0),
> +    _("Threshold for logging queries that examine too many rows, integer"));
> +  
> +  context(
> +    "threshold-rows-sent",
> +    po::value<uint32_constraint>(&query_log->sysvar_threshold_rows_sent)->default_value(0),
> +    _("Threshold for logging queries that return too many rows, integer"));
> +  
> +  context(
> +    "threshold-tmp-tables",
> +    po::value<uint32_constraint>(&query_log->sysvar_threshold_tmp_tables)->default_value(0),
> +    _("Threshold for logging queries that use too many temporary tables, integer"));
> +
> +  context(
> +    "threshold-warnings",
> +    po::value<uint32_constraint>(&query_log->sysvar_threshold_warnings)->default_value(0),
> +    _("Threshold for logging queries that cause too many warnings, integer"));
> +
> +  context(
> +    "threshold-session-time",
> +    po::value<uint32_constraint>(&query_log->sysvar_threshold_session_time)->default_value(0),
> +    _("Threshold for logging queries that are active too long, in seconds"));
> +
> +}
> +
> +/**
> + * @brief
> + *   Add query_log plugin to Drizzle and initalize query_log system variables.
> + *
> + * @details
> + *   This is where we plug into Drizzle and register our system variables.
> + *   Since this is called after init_options(), vm has either values from
> + *   the command line or defaults.  System variables corresponding to
> + *   command line options use the same public query_log variables so that
> + *   values from vm (the command line) are automatically reflected in the
> + *   system variable (SHOW VARIABLES).  This also makes changes to certain
> + *   system variables automatic/instant because when they're updated (e.g.
> + *   SET GLOBAL query_log_enabled=TRUE|FALSE) Drizzle changes the corresponding
> + *   public query_log variable.  Certain system variables, like query_log_file,
> + *   require more work to change, so they're handled by update functions like
> + *   update_file().
> + *
> + * @retval 0 Success
> + */
> +static int init(drizzled::module::Context &context)
> +{
> +  const module::option_map &vm= context.getOptions();
> +
> +  // Open the log file now that we have either an explicit value from the
> +  // command line (--query-log.file=FILE) or the default file.
> +  if (vm["file-enabled"].as<bool>())
> +    logger_file->openLogFile(vm["file"].as<string>().c_str());
> +
> +  // Plug into Drizzle!
> +  context.add(query_log);
> +
> +  // Register our system variables with Drizzle, e.g. query_log_enabled,
> +  // query_log_file, etc. in SHOW VARIABLES.
> +  context.registerVariable(
> +    new sys_var_bool_ptr(
> +      "enabled", &query_log->sysvar_enabled));
> +
> +  context.registerVariable(
> +    new sys_var_bool_ptr(
> +      "file_enabled", &query_log->sysvar_file_enabled, &update_file_enabled));
> +
> +  context.registerVariable(
> +    new sys_var_std_string(
> +      "file", query_log->sysvar_file, NULL, &update_file));
> +
> +  context.registerVariable(
> +    new sys_var_constrained_value<uint32_t>(
> +      "threshold_execution_time", query_log->sysvar_threshold_execution_time));
> +  
> +  context.registerVariable(
> +    new sys_var_constrained_value<uint32_t>(
> +      "threshold_lock_time", query_log->sysvar_threshold_lock_time));
> +  
> +  context.registerVariable(
> +    new sys_var_constrained_value<uint32_t>(
> +      "threshold_rows_examined", query_log->sysvar_threshold_rows_examined));
> +  
> +  context.registerVariable(
> +    new sys_var_constrained_value<uint32_t>(
> +      "threshold_rows_sent", query_log->sysvar_threshold_rows_sent));
> +  
> +  context.registerVariable(
> +    new sys_var_constrained_value<uint32_t>(
> +      "threshold_tmp_tables", query_log->sysvar_threshold_tmp_tables));
> +  
> +  context.registerVariable(
> +    new sys_var_constrained_value<uint32_t>(
> +      "threshold_warnings", query_log->sysvar_threshold_warnings));
> +
> +  context.registerVariable(
> +    new sys_var_constrained_value<uint32_t>(
> +      "threshold_session_time", query_log->sysvar_threshold_session_time));
> +
> +  return 0; // success
> +}
> +
> +} /* namespace drizzle_plugin */
> +
> +DRIZZLE_PLUGIN(drizzle_plugin::init, NULL, drizzle_plugin::init_options);
> 
> === added file 'plugin/query_log/plugin.ini'
> --- plugin/query_log/plugin.ini	1970-01-01 00:00:00 +0000
> +++ plugin/query_log/plugin.ini	2011-05-15 18:13:26 +0000
> @@ -0,0 +1,8 @@
> +[plugin]
> +title=Query Log
> +description=Log queries to a file.
> +version=1.0
> +author=Daniel Nichter
> +license=PLUGIN_LICENSE_GPL
> +sources=module.cc query_log.cc file.cc
> +headers=query_log.h file.h event.h
> 
> === added file 'plugin/query_log/query_log.cc'
> --- plugin/query_log/query_log.cc	1970-01-01 00:00:00 +0000
> +++ plugin/query_log/query_log.cc	2011-05-15 18:13:26 +0000
> @@ -0,0 +1,149 @@
> +/* -*- mode: c++; c-basic-offset: 2; indent-tabs-mode: nil; -*-
> + *  vim:expandtab:shiftwidth=2:tabstop=2:smarttab:
> + *
> + *  Copyright (C) 2011 Daniel Nichter
> + *
> + *  This program is free software; you can redistribute it and/or modify
> + *  it under the terms of the GNU General Public License as published by
> + *  the Free Software Foundation; version 2 of the License.
> + *
> + *  This program is distributed in the hope that it will be useful,
> + *  but WITHOUT ANY WARRANTY; without even the implied warranty of
> + *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
> + *  GNU General Public License for more details.
> + *
> + *  You should have received a copy of the GNU General Public License
> + *  along with this program; if not, write to the Free Software
> + *  Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA  02110-1301  USA
> + */
> +
> +#include <config.h>
> +#include <string>
> +#include <fcntl.h>
> +#include <drizzled/item.h>
> +#include <drizzled/module/option_map.h>
> +#include <drizzled/session.h>
> +#include <drizzled/session/times.h>
> +#include <drizzled/plugin.h>
> +#include "query_log.h"
> +
> +using namespace std;
> +using namespace drizzled;
> +using namespace plugin;
> +
> +QueryLog::QueryLog(bool enabled, QueryLoggerFile *logger_file) :
> +  drizzled::plugin::EventObserver("query_log"),
> +  sysvar_enabled(enabled),
> +  _logger_file(logger_file)
> +{
> +}
> +
> +QueryLog::~QueryLog()
> +{
> +}
> +
> +void QueryLog::registerSessionEventsDo(Session &, EventObserverList &observers)
> +{
> +  registerEvent(observers, AFTER_STATEMENT);
> +}
> +
> +bool QueryLog::observeEventDo(EventData &data)
> +{
> +  // Don't log and return successful if...
> +  if (not sysvar_enabled          // all logging is disabled
> +      || not sysvar_file_enabled) // or file logging is disabled
> +    return false;
> +
> +  switch (data.event) {
> +  case AFTER_STATEMENT:
> +    afterStatement((AfterStatementEventData &)data);
> +    break;
> +  default:
> +    fprintf(stderr, "query_log: Unexpected event '%s'\n",
> +      EventObserver::eventName(data.event));
> +  }
> +
> +  return false;
> +}
> +
> +bool QueryLog::afterStatement(AfterStatementEventData &data)
> +{
> +  Session *session= &data.session;
> +
> +  // For the moment we're only interestd in queries, not admin
> +  // command and such.
> +  if (session->command != COM_QUERY)
> +    return false;
> +
> +  // Query end time (microseconds from epoch)
> +  uint64_t t_mark= session->times.getCurrentTimestamp(false);
> +
> +  /**
> +   * Time values, first in microseconds so we can check the thresholds.
> +   */
> +  _event.execution_time= session->times.getElapsedTime();
> +  _event.lock_time= (t_mark - session->times.utime_after_lock);
> +  _event.session_time= (t_mark - session->times.getConnectMicroseconds());
> +
> +  /**
> +   * Check thresholds as soon as possible, return early if possible.
> +   * This avoid unnecessary work; i.e. don't construct the whole event
> +   * only to throw it away at the end because it fails a threshold.
> +   */
> +  if (   _event.execution_time < sysvar_threshold_execution_time
> +      || _event.lock_time      < sysvar_threshold_lock_time
> +      || _event.session_time   < sysvar_threshold_session_time)
> +    return false;
> +
> +  /**
> +   * Convert from microseconds to seconds, e.g. 42 to 0.000042
> +   * This is done for the user who may read the log.  It's a lot
> +   * easier to see half a second as 0.5 than 500000.
> +   */
> +  _event.execution_time= _event.execution_time * 0.000001;
> +  _event.lock_time= _event.lock_time * 0.000001;
> +  _event.session_time= _event.session_time * 0.000001;
> +
> +  /**
> +   * Integer values
> +   */
> +  _event.session_id= session->getSessionId();
> +  _event.query_id= session->getQueryId();
> +  _event.rows_examined= session->examined_row_count;
> +  _event.rows_sent= session->sent_row_count;
> +  _event.tmp_tables= session->tmp_table;
> +  _event.warnings= session->total_warn_count;
> +
> +  if (   _event.rows_examined < sysvar_threshold_rows_examined
> +      || _event.rows_sent     < sysvar_threshold_rows_sent
> +      || _event.tmp_tables    < sysvar_threshold_tmp_tables
> +      || _event.warnings      < sysvar_threshold_warnings)
> +    return false;
> +
> +  /**
> +   * Boolean values, as strings
> +   */
> +  _event.error= session->is_error() ? "true" : "false"; 
> + 
> +  /**
> +   * String values, may be blank
> +   */ 
> +  _event.schema= session->schema()->c_str();
> +
> +  /**
> +   * The query string
> +   */
> +  _event.query= session->getQueryString()->c_str();
> +
> +  /**
> +   * Timestamp values, convert from microseconds from epoch to
> +   * ISO timestamp like 2002-01-31T10:00:01.123456
> +   */
> +  boost::posix_time::ptime t_start= session->times.start_timer();
> +  _event.ts= boost::posix_time::to_iso_extended_string(t_start);
> +
> +  // Pass the event to the loggers.
> +  _logger_file->logEvent((const event_t *)&_event);
> +
> +  return false; // success
> +}
> 
> === added file 'plugin/query_log/query_log.h'
> --- plugin/query_log/query_log.h	1970-01-01 00:00:00 +0000
> +++ plugin/query_log/query_log.h	2011-05-15 18:13:26 +0000
> @@ -0,0 +1,74 @@
> +/*
> +  *  Copyright (C) 2011 Daniel Nichter
> + *
> + *  This program is free software; you can redistribute it and/or modify
> + *  it under the terms of the GNU General Public License as published by
> + *  the Free Software Foundation; version 2 of the License.
> + *
> + *  This program is distributed in the hope that it will be useful,
> + *  but WITHOUT ANY WARRANTY; without even the implied warranty of
> + *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
> + *  GNU General Public License for more details.
> + *
> + *  You should have received a copy of the GNU General Public License
> + *  along with this program; if not, write to the Free Software
> + *  Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA  02110-1301  USA
> + */
> +
> +#pragma once
> +
> +#include <drizzled/plugin/event_observer.h>
> +#include "file.h";
> +#include "event.h";
> +
> +namespace drizzled
> +{
> +namespace plugin
> +{
> +
> +/**
> + * @brief
> + *   QueryLog implements the query_log plugin.
> + *
> + * @details
> + *   This is our event observer plugin subclass that sits between Drizzle
> + *   and logger classes like QueryLoggerFile.  This class encapsulates and
> + *   manages data associated with the plugin: system variables and incoming
> + *   events.  The future plan is to have other logger classes, like
> + *   QueryLoggerTable or QueryLoggerUDPSocket.  So implemeting those should
> + *   be easy because this class abstracts plugin data management from actual
> + *   logging: it gets events from Drizzle, filters and prepares them, then
> + *   sends them to logger classes which only have to log them.
> + */
> +class QueryLog : public drizzled::plugin::EventObserver
> +{
> +public:
> +  QueryLog(bool enabled, QueryLoggerFile *logger_file);
> +  ~QueryLog();
> +
> +  void registerSessionEventsDo(Session &session, EventObserverList &observers);
> +  bool observeEventDo(EventData &);
> +  bool afterStatement(AfterStatementEventData &data);
> +
> +  /**
> +   * These are the query_log system variables.  So sysvar_enabled is
> +   * query_log_enabled in SHOW VARIABLES, etc.  They are all global and dynamic.
> +   */
> +  bool sysvar_enabled;
> +  bool sysvar_file_enabled;
> +  std::string sysvar_file;
> +  uint32_constraint sysvar_threshold_execution_time;
> +  uint32_constraint sysvar_threshold_lock_time;
> +  uint32_constraint sysvar_threshold_rows_examined;
> +  uint32_constraint sysvar_threshold_rows_sent;
> +  uint32_constraint sysvar_threshold_tmp_tables;
> +  uint32_constraint sysvar_threshold_warnings;
> +  uint32_constraint sysvar_threshold_session_time;
> +
> +private:
> +  QueryLoggerFile *_logger_file;
> +  event_t _event;
> +};
> +
> +} /* namespace plugin */
> +} /* namespace drizzled */
> 
> === added directory 'plugin/query_log/tests'
> === added file 'plugin/query_log/tests/check-query-log-attribute.pl'
> --- plugin/query_log/tests/check-query-log-attribute.pl	1970-01-01 00:00:00 +0000
> +++ plugin/query_log/tests/check-query-log-attribute.pl	2011-05-15 18:13:26 +0000
> @@ -0,0 +1,134 @@
> +#!/usr/bin/env perl
> +
> +use strict;
> +use warnings;
> +use English qw(-no_match_vars);
> +
> +my ($file, $attrib, $cmp, $val, $val2) = @ARGV;
> +if ( !$file || !$attrib ) {
> +   warn "Usage: check-query-log-values.pl FILE ATTRIBUTE [CMP VALUE [VALUE]]\n";
> +   exit 1;
> +}
> +
> +# Slurp the file.  There should be only 1 event.
> +open my $fh, "<", $file or die "Cannot open $file: $OS_ERROR";
> +my $event_text = '';
> +{
> +   local $INPUT_RECORD_SEPARATOR = "\n#\n";
> +   while ( defined(my $event = <$fh>) ) {
> +      $event_text = $event;
> +   }
> +}
> +close $fh;
> +my @event_lines = split /\n/, $event_text;
> +
> +my $event = parse_event(@event_lines);
> +
> +my @attribs = split /,/, $attrib;
> +my @vals    = split /,/, $val if $val;
> +my @vals2   = split /,/, $val2 if $val2;
> +
> +if ( $val ) {
> +   die "The number of ATTRIBUTEs and VALUEs does not match"
> +      if $#attribs != $#vals;
> +}
> +
> +print "Checking attributes and values of query $event->{arg}\n";
> +
> +for my $i (0..$#attribs) {
> +   my $attrib = lc $attribs[$i];
> +   my $val    = $vals[$i];
> +   my $val2   = $vals2[$i];
> +
> +   if ( $attrib eq 'all' ) {
> +      dump_event($event);
> +   }
> +   else {
> +      die "A CMP argument is required if ATTRIBUTE is not ALL"
> +         unless $cmp;
> +      die "A VALUE argument is required if ATTRIBUTE is not ALL"
> +         unless defined $val;
> +
> +      print "ERROR: attribute $attrib does not exist.\n"
> +         unless exists $event->{$attrib};
> +
> +      $cmp = lc $cmp;
> +
> +      my $ok = 0;
> +      my $event_val = $event->{$attrib};
> +      if ( $cmp eq '=' || $cmp eq 'equals' ) {
> +         $ok = 1 if defined $event_val && $event_val eq $val;
> +      }
> +      elsif ( $cmp eq 'matches' ) {
> +         $ok = 1 if defined $event_val && $event_val =~ m/$val/;
> +      }
> +      elsif ( $cmp eq 'between' ) {
> +         die "I need a second VALUE argument if CMP is BETWEEN"
> +            unless $val2;
> +         $ok = 1 if defined $event_val
> +            && $val <= $event_val && $event_val <= $val2;
> +      }
> +      else {
> +         die "Unknown CMP: $cmp";
> +      }
> +
> +      if ( $ok ) {
> +         # Don't print the matches pattern becaues it's probably some
> +         # variable value like a timestamp.
> +         print "$attrib value $cmp "
> +            . ($cmp eq 'matches' ? "" : "$val ")
> +            . ($cmp eq 'between' ? "and $val2 " : "")
> +            . "OK\n";
> +      }
> +      else {
> +         print "$attrib value $event_val does not '$cmp' $val"
> +            . ($cmp eq 'between' ? " and $val2" : "") . "\n"
> +            . "Event dump:\n";
> +         dump_event($event);
> +      }
> +   }
> +}
> +
> +sub parse_event {
> +   my (@event_lines) = @_;
> +   die "I need a event_lines argument" unless @event_lines;
> +
> +   my $rs = pop @event_lines;
> +   if ( $rs ne "#" ) {
> +      print "ERROR: Event does not end with the # record separator.\n";
> +   }
> +
> +   my @props;
> +   my $arg = '';
> +   my $lineno = 1;
> +   foreach my $line ( @event_lines ) { 
> +      next if $line =~ m/^$/;
> +      if ( $lineno == 1 ) { # timestamp
> +         push @props, 'ts', $line =~ m/^# (\S+)/;
> +      }
> +      elsif ( $lineno >= 2 && $lineno <= 4 ) { # ints, floats and bools
> +         push @props, $line =~ m/([a-z_]+)=(\S+)/g;
> +      }
> +      elsif ( $lineno == 5 ) { # strings
> +         push @props, $line =~ m/([a-z_]+)="([^"]*)"/;
> +      }
> +      else { # query
> +         $arg .= $line;
> +      }
> +      $lineno++;
> +   }
> +
> +   chomp $arg;
> +   push @props, 'arg', $arg;
> +
> +   my $event = { @props };
> +
> +   return $event;
> +}
> +
> +sub dump_event {
> +   my ($event) = @_;
> +   foreach my $attrib ( sort keys %$event ) {
> +      print "$attrib=$event->{$attrib}\n";
> +   }
> +}
> 
> === added directory 'plugin/query_log/tests/r'
> === added file 'plugin/query_log/tests/r/check_query_log_attribute.result'
> --- plugin/query_log/tests/r/check_query_log_attribute.result	1970-01-01 00:00:00 +0000
> +++ plugin/query_log/tests/r/check_query_log_attribute.result	2011-05-15 18:13:26 +0000
> @@ -0,0 +1,14 @@
> +Checking attributes and values of query SET GLOBAL query_log_file_enabled=TRUE;
> +arg=SET GLOBAL query_log_file_enabled=TRUE;
> +error=false
> +execution_time=7.890123
> +lock_time=4.567890
> +query_id=2
> +rows_examined=3
> +rows_sent=4
> +schema=test
> +session_id=1
> +session_time=1.234567
> +tmp_tables=5
> +ts=1234-56-78T90:12:34.567890
> +warnings=6
> 
> === added file 'plugin/query_log/tests/r/file.result'
> --- plugin/query_log/tests/r/file.result	1970-01-01 00:00:00 +0000
> +++ plugin/query_log/tests/r/file.result	2011-05-15 18:13:26 +0000
> @@ -0,0 +1,162 @@
> +Log file does not exist
> +select * from data_dictionary.plugins join data_dictionary.modules on plugins.plugin_name=modules.module_name where plugin_name='query_log';
> +PLUGIN_NAME	query_log
> +PLUGIN_TYPE	EventObserver
> +IS_ACTIVE	YES
> +MODULE_NAME	query_log
> +MODULE_NAME	query_log
> +MODULE_VERSION	1.0
> +MODULE_AUTHOR	Daniel Nichter
> +IS_BUILTIN	NO
> +MODULE_LIBRARY	query_log
> +MODULE_DESCRIPTION	Query Log
> +MODULE_LICENSE	GPL
> +SELECT @@query_log_enabled, @@query_log_file_enabled;
> +@@query_log_enabled	@@query_log_file_enabled
> +1	0
> +SELECT 1;
> +1
> +1
> +SET GLOBAL query_log_file_enabled=TRUE;
> +SELECT @@query_log_enabled, @@query_log_file_enabled;
> +@@query_log_enabled	@@query_log_file_enabled
> +1	1
> +# 0000-00-00T00:00:00.000000
> +# session_id=0 query_id=0 rows_examined=0 rows_sent=0 tmp_tables=0 warnings=0
> +# execution_time=0.000000 lock_time=0.000000 session_time=0.000000
> +# error=false
> +# schema="test"
> +SET GLOBAL query_log_file_enabled=TRUE;
> +#
> +# 0000-00-00T00:00:00.000000
> +# session_id=0 query_id=0 rows_examined=0 rows_sent=0 tmp_tables=0 warnings=0
> +# execution_time=0.000000 lock_time=0.000000 session_time=0.000000
> +# error=false
> +# schema="test"
> +SELECT @@query_log_enabled, @@query_log_file_enabled;
> +#
> +SET GLOBAL query_log_enabled=FALSE;
> +SELECT @@query_log_enabled, @@query_log_file_enabled;
> +@@query_log_enabled	@@query_log_file_enabled
> +0	1
> +SELECT 2;
> +2
> +2
> +# 0000-00-00T00:00:00.000000
> +# session_id=0 query_id=0 rows_examined=0 rows_sent=0 tmp_tables=0 warnings=0
> +# execution_time=0.000000 lock_time=0.000000 session_time=0.000000
> +# error=false
> +# schema="test"
> +SET GLOBAL query_log_file_enabled=TRUE;
> +#
> +# 0000-00-00T00:00:00.000000
> +# session_id=0 query_id=0 rows_examined=0 rows_sent=0 tmp_tables=0 warnings=0
> +# execution_time=0.000000 lock_time=0.000000 session_time=0.000000
> +# error=false
> +# schema="test"
> +SELECT @@query_log_enabled, @@query_log_file_enabled;
> +#
> +SET GLOBAL query_log_file_enabled=FALSE;
> +SELECT @@query_log_enabled, @@query_log_file_enabled;
> +@@query_log_enabled	@@query_log_file_enabled
> +0	0
> +SET GLOBAL query_log_file="DRIZZLETEST_VARDIR/query-2.log";
> +SELECT @@query_log_enabled, @@query_log_file_enabled, @@query_log_file;
> +@@query_log_enabled	@@query_log_file_enabled	@@query_log_file
> +0	0	DRIZZLETEST_VARDIR/query-2.log
> +Log file does not exist
> +SET GLOBAL query_log_enabled=TRUE;
> +SET GLOBAL query_log_file_enabled=TRUE;
> +SELECT 'this is the second log file';
> +this is the second log file
> +this is the second log file
> +Log file exists
> +# 0000-00-00T00:00:00.000000
> +# session_id=0 query_id=00 rows_examined=0 rows_sent=0 tmp_tables=0 warnings=0
> +# execution_time=0.000000 lock_time=0.000000 session_time=0.000000
> +# error=false
> +# schema="test"
> +SET GLOBAL query_log_file_enabled=TRUE;
> +#
> +# 0000-00-00T00:00:00.000000
> +# session_id=0 query_id=00 rows_examined=0 rows_sent=0 tmp_tables=0 warnings=0
> +# execution_time=0.000000 lock_time=0.000000 session_time=0.000000
> +# error=false
> +# schema="test"
> +SELECT 'this is the second log file';
> +#
> +SET GLOBAL query_log_file="DRIZZLETEST_VARDIR/query-3.log";
> +SELECT @@query_log_enabled, @@query_log_file_enabled, @@query_log_file;
> +@@query_log_enabled	@@query_log_file_enabled	@@query_log_file
> +1	1	DRIZZLETEST_VARDIR/query-3.log
> +Log file exists
> +SELECT 'this is the third log file';
> +this is the third log file
> +this is the third log file
> +# 0000-00-00T00:00:00.000000
> +# session_id=0 query_id=00 rows_examined=0 rows_sent=0 tmp_tables=0 warnings=0
> +# execution_time=0.000000 lock_time=0.000000 session_time=0.000000
> +# error=false
> +# schema="third-log-file"
> +SET GLOBAL query_log_file="third-log-file";
> +#
> +# 0000-00-00T00:00:00.000000
> +# session_id=0 query_id=00 rows_examined=0 rows_sent=0 tmp_tables=0 warnings=0
> +# execution_time=0.000000 lock_time=0.000000 session_time=0.000000
> +# error=false
> +# schema="third-log-file"
> +SELECT @@query_log_enabled, @@query_log_file_enabled, @@query_log_file;
> +#
> +# 0000-00-00T00:00:00.000000
> +# session_id=0 query_id=00 rows_examined=0 rows_sent=0 tmp_tables=0 warnings=0
> +# execution_time=0.000000 lock_time=0.000000 session_time=0.000000
> +# error=false
> +# schema="third-log-file"
> +SELECT 'this is the third log file';
> +#
> +# 0000-00-00T00:00:00.000000
> +# session_id=0 query_id=0 rows_examined=0 rows_sent=0 tmp_tables=0 warnings=0
> +# execution_time=0.000000 lock_time=0.000000 session_time=0.000000
> +# error=false
> +# schema="test"
> +SET GLOBAL query_log_file_enabled=TRUE;
> +#
> +# 0000-00-00T00:00:00.000000
> +# session_id=0 query_id=0 rows_examined=0 rows_sent=0 tmp_tables=0 warnings=0
> +# execution_time=0.000000 lock_time=0.000000 session_time=0.000000
> +# error=false
> +# schema="test"
> +SELECT @@query_log_enabled, @@query_log_file_enabled;
> +#
> +# 0000-00-00T00:00:00.000000
> +# session_id=0 query_id=00 rows_examined=0 rows_sent=0 tmp_tables=0 warnings=0
> +# execution_time=0.000000 lock_time=0.000000 session_time=0.000000
> +# error=false
> +# schema="test"
> +SET GLOBAL query_log_file_enabled=TRUE;
> +#
> +# 0000-00-00T00:00:00.000000
> +# session_id=0 query_id=00 rows_examined=0 rows_sent=0 tmp_tables=0 warnings=0
> +# execution_time=0.000000 lock_time=0.000000 session_time=0.000000
> +# error=false
> +# schema="test"
> +SELECT 'this is the second log file';
> +#
> +SET GLOBAL query_log_file="DRIZZLETEST_VARDIR/query.log";
> +Checking attributes and values of query SELECT DATE(NOW());
> +ts value matches OK
> +Checking attributes and values of query SELECT DATE(NOW());
> +execution_time value matches OK
> +lock_time value matches OK
> +session_time value matches OK
> +Checking attributes and values of query SELECT DATE(NOW());
> +rows_examined value equals 0 OK
> +tmp_tables value equals 0 OK
> +warnings value equals 0 OK
> +error value equals false OK
> +schema value equals test OK
> +SELECT SLEEP(0.5);
> +SLEEP(0.5)
> +0
> +Checking attributes and values of query SELECT SLEEP(0.5);
> +execution_time value between 0.5 and 0.59 OK
> 
> === added file 'plugin/query_log/tests/r/thresholds.result'
> --- plugin/query_log/tests/r/thresholds.result	1970-01-01 00:00:00 +0000
> +++ plugin/query_log/tests/r/thresholds.result	2011-05-15 18:13:26 +0000
> @@ -0,0 +1,54 @@
> +SET GLOBAL query_log_file="DRIZZLETEST_VARDIR/query.log";
> +SET GLOBAL query_log_file_enabled=TRUE;
> +SHOW VARIABLES LIKE 'query_log_threshold%';
> +Variable_name	Value
> +query_log_threshold_execution_time	0
> +query_log_threshold_lock_time	0
> +query_log_threshold_rows_examined	0
> +query_log_threshold_rows_sent	0
> +query_log_threshold_session_time	0
> +query_log_threshold_tmp_tables	0
> +query_log_threshold_warnings	0
> +SET GLOBAL query_log_threshold_execution_time=500000;
> +SELECT @@query_log_threshold_execution_time;
> +@@query_log_threshold_execution_time
> +500000
> +
> +SELECT SLEEP(0.4);
> +SLEEP(0.4)
> +0
> +
> +SELECT SLEEP(0.5);
> +SLEEP(0.5)
> +0
> +Checking attributes and values of query SELECT SLEEP(0.5);
> +execution_time value between 0.5 and 0.59 OK
> +Checking attributes and values of query SELECT SLEEP(0.5);
> +arg value equals SELECT SLEEP(0.5); OK
> +
> +# 0000-00-00T00:00:00.000000
> +# session_id=0 query_id=0 rows_examined=0 rows_sent=0 tmp_tables=0 warnings=0
> +# execution_time=0.000000 lock_time=0.000000 session_time=0.000000
> +# error=false
> +# schema="test"
> +SELECT SLEEP(0.0);
> +#
> +SET GLOBAL query_log_file_enabled=FALSE;
> +SET GLOBAL query_log_file_enabled=TRUE;
> +SET GLOBAL query_log_threshold_execution_time=0;
> +SELECT @@query_log_threshold_execution_time;
> +@@query_log_threshold_execution_time
> +0
> +SELECT 'one';
> +one
> +one
> +Checking attributes and values of query SELECT 'one';
> +arg value equals SELECT 'one'; OK
> +
> +# 0000-00-00T00:00:00.000000
> +# session_id=0 query_id=00 rows_examined=0 rows_sent=0 tmp_tables=0 warnings=0
> +# execution_time=0.000000 lock_time=0.000000 session_time=0.000000
> +# error=false
> +# schema="test"
> +SELECT 'one';
> +#
> 
> === added directory 'plugin/query_log/tests/samples'
> === added file 'plugin/query_log/tests/samples/sample-event.log'
> --- plugin/query_log/tests/samples/sample-event.log	1970-01-01 00:00:00 +0000
> +++ plugin/query_log/tests/samples/sample-event.log	2011-05-15 18:13:26 +0000
> @@ -0,0 +1,7 @@
> +# 1234-56-78T90:12:34.567890
> +# session_id=1 query_id=2 rows_examined=3 rows_sent=4 tmp_tables=5 warnings=6
> +# execution_time=7.890123 lock_time=4.567890 session_time=1.234567
> +# error=false
> +# schema="test"
> +SET GLOBAL query_log_file_enabled=TRUE;
> +#
> 
> === added directory 'plugin/query_log/tests/t'
> === added file 'plugin/query_log/tests/t/check_query_log_attribute.test'
> --- plugin/query_log/tests/t/check_query_log_attribute.test	1970-01-01 00:00:00 +0000
> +++ plugin/query_log/tests/t/check_query_log_attribute.test	2011-05-15 18:13:26 +0000
> @@ -0,0 +1,9 @@
> +
> +# ###########################################################################
> +# This is *not* a test for the query_log pluging but rather a test for the
> +# helper script check-query-log-attribute.pl which the real query_log tests
> +# use to parse and check query logs.
> +# ###########################################################################
> +
> +# Make sure the script correctly parses a log event.
> +--exec $TOP_SRCDIR/plugin/query_log/tests/check-query-log-attribute.pl $TOP_SRCDIR/plugin/query_log/tests/samples/sample-event.log all
> 
> === added file 'plugin/query_log/tests/t/file.test'
> --- plugin/query_log/tests/t/file.test	1970-01-01 00:00:00 +0000
> +++ plugin/query_log/tests/t/file.test	2011-05-15 18:13:26 +0000
> @@ -0,0 +1,119 @@
> +
> +# ###########################################################################
> +# First we check the log file itself: that it can be enabled and disabled,
> +# that the plugin only writes to it when enabled, and that it can be changed
> +# both when disabled (and then re-enabled) and changed when enabled (close
> +# old log file, open and write to new log file).
> +# ###########################################################################
> +
> +# The query_log plugin is enabled by default, but query_log_file_enabled is
> +# disabled by default, so the plugin should not have opened/created the log
> +# file yet.
> +--exec if [ -f $DRIZZLETEST_VARDIR/query.log ]; then echo "Log file exists"; else echo "Log file does not exist"; fi
> +
> +# Does the plugin crash Drizzle on startup?  Hopefully not.
> +# Is it actually plugged in?  It should be.
> +# Can we still exec queries without crashing Drizzle?  Let's hope so.
> +--vertical_results
> +select * from data_dictionary.plugins join data_dictionary.modules on plugins.plugin_name=modules.module_name where plugin_name='query_log';
> +--horizontal_results
> +
> +# When the query_log plugin is added, it's enabled by default, but all its
> +# destinations (currently it has just one: file) are disabled.  So this should
> +# return 1, 0.
> +SELECT @@query_log_enabled, @@query_log_file_enabled;
> +
> +# This query should not be logged because, although the plugin is enabled,
> +# the query log file is disabled.
> +SELECT 1;
> +
> +# Enable the query log file.  The first query logged is the SET.  The sed
> +# command changes all numbers to zeros because most the value are variable:
> +# timestamps, execution times, etc.
> +SET GLOBAL query_log_file_enabled=TRUE;
> +SELECT @@query_log_enabled, @@query_log_file_enabled;
> +--system sed -i '' 's/[0-9]/0/g' $DRIZZLETEST_VARDIR/query.log
> +--cat_file $DRIZZLETEST_VARDIR/query.log
> +
> +# Disable the query_log plugin globally, i.e. the master switch.  Neither of
> +# these three queries should show in the log; so the log will be identical to
> +# before being disabled.
> +SET GLOBAL query_log_enabled=FALSE;
> +SELECT @@query_log_enabled, @@query_log_file_enabled;
> +SELECT 2;
> +--system sed -i '' 's/[0-9]/0/g' $DRIZZLETEST_VARDIR/query.log
> +--cat_file $DRIZZLETEST_VARDIR/query.log
> +
> +# Disable and change the qury log file.  The plugin should not actually open
> +# the new file until query_log_file_enabled is true again, so the second SELECT
> +# should should the new log file for @@query_log_file but the exec should
> +# show that the file doesn't exist yet.
> +SET GLOBAL query_log_file_enabled=FALSE;
> +SELECT @@query_log_enabled, @@query_log_file_enabled;
> +--replace_result $DRIZZLETEST_VARDIR DRIZZLETEST_VARDIR
> +eval SET GLOBAL query_log_file="$DRIZZLETEST_VARDIR/query-2.log";
> +--replace_result $DRIZZLETEST_VARDIR DRIZZLETEST_VARDIR
> +SELECT @@query_log_enabled, @@query_log_file_enabled, @@query_log_file;
> +--exec if [ -f $DRIZZLETEST_VARDIR/query-2.log ]; then echo "Log file exists"; else echo "Log file does not exist"; fi
> +
> +# Now enable the log file again and it should contain just the second SET and
> +# the SELECT.
> +SET GLOBAL query_log_enabled=TRUE;
> +SET GLOBAL query_log_file_enabled=TRUE;
> +SELECT 'this is the second log file';
> +--exec if [ -f $DRIZZLETEST_VARDIR/query-2.log ]; then echo "Log file exists"; else echo "Log file does not exist"; fi
> +--system sed -i '' 's/[0-9]/0/g' $DRIZZLETEST_VARDIR/query-2.log
> +--cat_file $DRIZZLETEST_VARDIR/query-2.log
> +
> +# Finally, change the log file while it's enabled.
> +--replace_result $DRIZZLETEST_VARDIR DRIZZLETEST_VARDIR
> +eval SET GLOBAL query_log_file="$DRIZZLETEST_VARDIR/query-3.log";
> +--replace_result $DRIZZLETEST_VARDIR DRIZZLETEST_VARDIR
> +SELECT @@query_log_enabled, @@query_log_file_enabled, @@query_log_file;
> +--exec if [ -f $DRIZZLETEST_VARDIR/query-2.log ]; then echo "Log file exists"; else echo "Log file does not exist"; fi
> +SELECT 'this is the third log file';
> +--system sed -i '' 's/[0-9]/0/g' $DRIZZLETEST_VARDIR/query-3.log
> +--system sed -i '' 's/".*"/"third-log-file"/' $DRIZZLETEST_VARDIR/query-3.log
> +--cat_file $DRIZZLETEST_VARDIR/query-3.log
> +
> +# And just to be sure, let's cat the previous logs to make sure they don't
> +# have any queries that they shouldn't have.
> +--system sed -i '' 's/[0-9]/0/g' $DRIZZLETEST_VARDIR/query.log
> +--cat_file $DRIZZLETEST_VARDIR/query.log
> +--system sed -i '' 's/[0-9]/0/g' $DRIZZLETEST_VARDIR/query-2.log
> +--cat_file $DRIZZLETEST_VARDIR/query-2.log
> +
> +# Done.  Cleanup for other tests.
> +--replace_result $DRIZZLETEST_VARDIR DRIZZLETEST_VARDIR
> +eval SET GLOBAL query_log_file="$DRIZZLETEST_VARDIR/query.log";
> +--remove_file $DRIZZLETEST_VARDIR/query-2.log
> +--remove_file $DRIZZLETEST_VARDIR/query-3.log
> +
> +# ###########################################################################
> +# Now check that the logged values are correct.
> +# ###########################################################################
> +
> +# Clear previous events from the log.
> +--exec echo "" > $DRIZZLETEST_VARDIR/query.log
> +
> +# The first line of an event should be an ISO timestamp like
> +# YYYY-MM-DDTHH:MM:SS.uuuuuu.  We just check that the start of the ts
> +# matches today's date.
> +let $today= `SELECT DATE(NOW())`;
> +--exec $TOP_SRCDIR/plugin/query_log/tests/check-query-log-attribute.pl $DRIZZLETEST_VARDIR/query.log ts matches "^$today"
> +
> +# The 3rd line of an event should be microsecond times like 1.123456
> +--exec $TOP_SRCDIR/plugin/query_log/tests/check-query-log-attribute.pl $DRIZZLETEST_VARDIR/query.log execution_time,lock_time,session_time matches '\d\.\d{6}','\d\.\d{6}','\d\.\d{6}'
> +
> +# The 2nd line (rows_examined, etc.) are ints, error on the 4th line is bool,
> +# and schema on the 5th line is a double-quoted string.
> +--exec $TOP_SRCDIR/plugin/query_log/tests/check-query-log-attribute.pl $DRIZZLETEST_VARDIR/query.log rows_examined,tmp_tables,warnings,error,schema equals 0,0,0,false,test
> +
> +# Test that execution_time is accurate: if we sleep for 0.5s, execution time
> +# should be at least 0.50 and probably a few microseconds longer.
> +SELECT SLEEP(0.5);
> +--exec $TOP_SRCDIR/plugin/query_log/tests/check-query-log-attribute.pl $DRIZZLETEST_VARDIR/query.log execution_time between 0.5 0.59
> +
> +# ###########################################################################
> +# Done.
> +# ###########################################################################
> 
> === added file 'plugin/query_log/tests/t/master.opt'
> --- plugin/query_log/tests/t/master.opt	1970-01-01 00:00:00 +0000
> +++ plugin/query_log/tests/t/master.opt	2011-05-15 18:13:26 +0000
> @@ -0,0 +1,1 @@
> +--plugin-add query-log --query-log.file $DRIZZLETEST_VARDIR/query.log
> 
> === added file 'plugin/query_log/tests/t/thresholds.test'
> --- plugin/query_log/tests/t/thresholds.test	1970-01-01 00:00:00 +0000
> +++ plugin/query_log/tests/t/thresholds.test	2011-05-15 18:13:26 +0000
> @@ -0,0 +1,68 @@
> +
> +# ###########################################################################
> +# This tests the various query_log_threshold_ variables.
> +# ###########################################################################
> +
> +# First make sure the query log is on.
> +--replace_result $DRIZZLETEST_VARDIR DRIZZLETEST_VARDIR
> +eval SET GLOBAL query_log_file="$DRIZZLETEST_VARDIR/query.log";
> +--replace_result $DRIZZLETEST_VARDIR DRIZZLETEST_VARDIR
> +SET GLOBAL query_log_file_enabled=TRUE;
> +
> +# Make sure we have all our threshold variables and that they're all
> +# off (zero) by default.
> +SHOW VARIABLES LIKE 'query_log_threshold%';
> +
> +# ###########################################################################
> +# query_log_execution_time
> +# ###########################################################################
> +
> +# Set a 0.5s execution time threshold.
> +SET GLOBAL query_log_threshold_execution_time=500000;
> +SELECT @@query_log_threshold_execution_time;
> +
> +# Clear log file.
> +--exec echo "" > $DRIZZLETEST_VARDIR/query.log
> +# Double-check that log file is clear.
> +--cat_file $DRIZZLETEST_VARDIR/query.log
> +
> +# This query should *not* log since it's below the threshold.
> +SELECT SLEEP(0.4);
> +# This should not print anything.
> +--cat_file $DRIZZLETEST_VARDIR/query.log
> +
> +# This query should log since it's just a few microseconds past the threshold.
> +SELECT SLEEP(0.5);
> +--exec $TOP_SRCDIR/plugin/query_log/tests/check-query-log-attribute.pl $DRIZZLETEST_VARDIR/query.log execution_time between 0.5 0.59
> +--exec $TOP_SRCDIR/plugin/query_log/tests/check-query-log-attribute.pl $DRIZZLETEST_VARDIR/query.log arg equals 'SELECT SLEEP(0.5);'
> +
> +# We zero-out the values so the event is kind of useless; that's why we check
> +# it with check-query-log-attribute.pl.  We print it just to make sure there's
> +# only 1 event, i.e. that the sleep(0.4) really wasn't logged.
> +# The extra sed line here accounts for the query ids becoming double-digit
> +# when the whole test suite is ran; it's single when only this test file is run.
> +--system sed -i '' 's/[0-9]/0/g' $DRIZZLETEST_VARDIR/query.log
> +--system sed -i '' 's/query_id=00/query_id=0/g' $DRIZZLETEST_VARDIR/query.log
> +--cat_file $DRIZZLETEST_VARDIR/query.log
> +
> +# query_log doesn't like when sed modifies the log file in-place (-i).
> +# Unless we re-open the log file, no more queries will be logged.
> +SET GLOBAL query_log_file_enabled=FALSE;
> +SET GLOBAL query_log_file_enabled=TRUE;
> +
> +# Set query_log_threshold_execution_time back to zero.
> +SET GLOBAL query_log_threshold_execution_time=0;
> +SELECT @@query_log_threshold_execution_time;
> +--exec echo "" > $DRIZZLETEST_VARDIR/query.log
> +SELECT 'one';
> +--exec $TOP_SRCDIR/plugin/query_log/tests/check-query-log-attribute.pl $DRIZZLETEST_VARDIR/query.log arg equals "SELECT 'one';"
> +--system sed -i '' 's/[0-9]/0/g' $DRIZZLETEST_VARDIR/query.log
> +--cat_file $DRIZZLETEST_VARDIR/query.log
> +
> +# ###########################################################################
> +# TODO: the other threshold variables
> +# ###########################################################################
> +
> +# ###########################################################################
> +# Done.
> +# ###########################################################################
>