~drizzle-trunk/drizzle/development

« back to all changes in this revision

Viewing changes to plugin/logging_query/logging_query.cc

  • Committer: Mark Atwood
  • Date: 2010-06-24 03:15:21 UTC
  • mto: (1637.2.4 build)
  • mto: This revision was merged to the branch mainline in revision 1639.
  • Revision ID: me@mark.atwood.name-20100624031521-gafmppfbf5afm68w
new syslog module, with plugins for query log, error message, and SYSLOG() function

Show diffs side-by-side

added added

removed removed

Lines of Context:
1
1
/* -*- mode: c++; c-basic-offset: 2; indent-tabs-mode: nil; -*-
2
2
 *  vim:expandtab:shiftwidth=2:tabstop=2:smarttab:
3
3
 *
4
 
 *  Copyright (C) 2008, 2009 Sun Microsystems, Inc.
 
4
 *  Copyright (C) 2008,2009 Sun Microsystems
5
5
 *
6
6
 *  This program is free software; you can redistribute it and/or modify
7
7
 *  it under the terms of the GNU General Public License as published by
17
17
 *  Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA  02110-1301  USA
18
18
 */
19
19
 
20
 
#include <config.h>
 
20
#include "config.h"
21
21
#include <drizzled/plugin/logging.h>
22
22
#include <drizzled/gettext.h>
23
23
#include <drizzled/session.h>
29
29
#include <fcntl.h>
30
30
#include <string>
31
31
#include <boost/format.hpp>
32
 
#include <boost/program_options.hpp>
33
 
#include <drizzled/module/option_map.h>
 
32
 
34
33
#include <cstdio>
35
 
#include <cerrno>
36
34
 
37
 
namespace po= boost::program_options;
38
35
using namespace drizzled;
39
36
using namespace std;
40
37
 
41
38
#define ESCAPE_CHAR      '\\'
42
39
#define SEPARATOR_CHAR   ','
43
40
 
44
 
namespace drizzle_plugin
45
 
{
46
 
 
47
41
static bool sysvar_logging_query_enable= false;
 
42
static char* sysvar_logging_query_filename= NULL;
 
43
static char* sysvar_logging_query_pcre= NULL;
48
44
/* TODO fix these to not be unsigned long once we have sensible sys_var system */
49
 
static uint32_constraint sysvar_logging_query_threshold_slow;
50
 
static uint32_constraint sysvar_logging_query_threshold_big_resultset;
51
 
static uint32_constraint sysvar_logging_query_threshold_big_examined;
 
45
static unsigned long sysvar_logging_query_threshold_slow= 0;
 
46
static unsigned long sysvar_logging_query_threshold_big_resultset= 0;
 
47
static unsigned long sysvar_logging_query_threshold_big_examined= 0;
 
48
 
 
49
/* stolen from mysys/my_getsystime
 
50
   until the Session has a good utime "now" we can use
 
51
   will have to use this instead */
 
52
 
 
53
static uint64_t get_microtime()
 
54
{
 
55
#if defined(HAVE_GETHRTIME)
 
56
  return gethrtime()/1000;
 
57
#else
 
58
  uint64_t newtime;
 
59
  struct timeval t;
 
60
  /*
 
61
    The following loop is here because gettimeofday may fail on some systems
 
62
  */
 
63
  while (gettimeofday(&t, NULL) != 0) {}
 
64
  newtime= (uint64_t)t.tv_sec * 1000000 + t.tv_usec;
 
65
  return newtime;
 
66
#endif  /* defined(HAVE_GETHRTIME) */
 
67
}
52
68
 
53
69
/* quote a string to be safe to include in a CSV line
54
70
   that means backslash quoting all commas, doublequotes, backslashes,
143
159
 
144
160
class Logging_query: public drizzled::plugin::Logging
145
161
{
146
 
  const std::string _filename;
147
 
  const std::string _query_pcre;
148
162
  int fd;
149
163
  pcre *re;
150
164
  pcre_extra *pe;
154
168
 
155
169
public:
156
170
 
157
 
  Logging_query(const std::string &filename,
158
 
                const std::string &query_pcre) :
159
 
    drizzled::plugin::Logging("Logging_query"),
160
 
    _filename(filename),
161
 
    _query_pcre(query_pcre),
162
 
    fd(-1), re(NULL), pe(NULL),
163
 
    formatter("%1%,%2%,%3%,\"%4%\",\"%5%\",\"%6%\",%7%,%8%,"
164
 
              "%9%,%10%,%11%,%12%,%13%,%14%,\"%15%\"\n")
 
171
  Logging_query()
 
172
    : drizzled::plugin::Logging("Logging_query"),
 
173
      fd(-1), re(NULL), pe(NULL),
 
174
      formatter("%1%,%2%,%3%,\"%4%\",\"%5%\",\"%6%\",%7%,%8%,"
 
175
                "%9%,%10%,%11%,%12%,%13%,%14%,\"%15%\"\n")
165
176
  {
166
177
 
167
178
    /* if there is no destination filename, dont bother doing anything */
168
 
    if (_filename.empty())
 
179
    if (sysvar_logging_query_filename == NULL)
169
180
      return;
170
181
 
171
 
    fd= open(_filename.c_str(),
 
182
    fd= open(sysvar_logging_query_filename,
172
183
             O_WRONLY | O_APPEND | O_CREAT,
173
184
             S_IRUSR|S_IWUSR);
174
 
 
175
185
    if (fd < 0)
176
186
    {
177
 
      sql_perror( _("fail open()"), _filename);
 
187
      errmsg_printf(ERRMSG_LVL_ERROR, _("fail open() fn=%s er=%s\n"),
 
188
                    sysvar_logging_query_filename,
 
189
                    strerror(errno));
178
190
      return;
179
191
    }
180
192
 
181
 
    if (not _query_pcre.empty())
 
193
    if (sysvar_logging_query_pcre != NULL)
182
194
    {
183
195
      const char *this_pcre_error;
184
196
      int this_pcre_erroffset;
185
 
      re= pcre_compile(_query_pcre.c_str(), 0, &this_pcre_error,
 
197
      re= pcre_compile(sysvar_logging_query_pcre, 0, &this_pcre_error,
186
198
                       &this_pcre_erroffset, NULL);
187
199
      pe= pcre_study(re, 0, &this_pcre_error);
188
200
      /* TODO emit error messages if there is a problem */
226
238
    // return if not enabled or query was too fast or resultset was too small
227
239
    if (sysvar_logging_query_enable == false)
228
240
      return false;
229
 
    if (session->sent_row_count < sysvar_logging_query_threshold_big_resultset.get())
230
 
      return false;
231
 
    if (session->examined_row_count < sysvar_logging_query_threshold_big_examined.get())
232
 
      return false;
233
 
 
234
 
    /*
235
 
      TODO, the session object should have a "utime command completed"
236
 
      inside itself, so be more accurate, and so this doesnt have to
237
 
      keep calling current_utime, which can be slow.
238
 
    */
239
 
    uint64_t t_mark= session->getCurrentTimestamp(false);
240
 
 
241
 
    if (session->getElapsedTime() < (sysvar_logging_query_threshold_slow.get()))
242
 
      return false;
243
 
 
244
 
    Session::QueryString query_string(session->getQueryString());
 
241
    if (session->sent_row_count < sysvar_logging_query_threshold_big_resultset)
 
242
      return false;
 
243
    if (session->examined_row_count < sysvar_logging_query_threshold_big_examined)
 
244
      return false;
 
245
 
 
246
    /* TODO, the session object should have a "utime command completed"
 
247
       inside itself, so be more accurate, and so this doesnt have to
 
248
       keep calling current_utime, which can be slow */
 
249
  
 
250
    uint64_t t_mark= get_microtime();
 
251
  
 
252
    if ((t_mark - session->start_utime) < (sysvar_logging_query_threshold_slow))
 
253
      return false;
 
254
 
245
255
    if (re)
246
256
    {
247
257
      int this_pcre_rc;
248
 
      this_pcre_rc= pcre_exec(re, pe, query_string->c_str(), query_string->length(), 0, 0, NULL, 0);
 
258
      this_pcre_rc= pcre_exec(re, pe, session->query.c_str(), session->query.length(), 0, 0, NULL, 0);
249
259
      if (this_pcre_rc < 0)
250
260
        return false;
251
261
    }
255
265
    
256
266
    // Since quotify() builds the quoted string incrementally, we can
257
267
    // avoid some reallocating if we reserve some space up front.
258
 
    qs.reserve(query_string->length());
 
268
    qs.reserve(session->getQueryLength());
259
269
    
260
 
    quotify(*query_string, qs);
 
270
    quotify(session->getQueryString(), qs);
261
271
    
262
272
    // to avoid trying to printf %s something that is potentially NULL
263
 
    util::string::const_shared_ptr schema(session->schema());
264
 
    const char *dbs= (schema and not schema->empty()) ? schema->c_str() : "";
 
273
    const char *dbs= session->db.empty() ? "" : session->db.c_str();
265
274
 
266
275
    formatter % t_mark
267
276
              % session->thread_id
268
277
              % session->getQueryId()
269
278
              % dbs
270
279
              % qs
271
 
              % getCommandName(session->command)
 
280
              % command_name[session->command].str
272
281
              % (t_mark - session->getConnectMicroseconds())
273
 
              % session->getElapsedTime()
 
282
              % (t_mark - session->start_utime)
274
283
              % (t_mark - session->utime_after_lock)
275
284
              % session->sent_row_count
276
285
              % session->examined_row_count
277
286
              % session->tmp_table
278
287
              % session->total_warn_count
279
288
              % session->getServerId()
280
 
              % getServerHostname();
 
289
              % glob_hostname;
281
290
 
282
291
    string msgbuf= formatter.str();
283
292
 
289
298
  }
290
299
};
291
300
 
 
301
static Logging_query *handler= NULL;
 
302
 
292
303
static int logging_query_plugin_init(drizzled::module::Context &context)
293
304
{
294
 
 
295
 
  const module::option_map &vm= context.getOptions();
296
 
 
297
 
  if (vm.count("filename") > 0)
298
 
  {
299
 
    context.add(new Logging_query(vm["filename"].as<string>(),
300
 
                                  vm["pcre"].as<string>()));
301
 
    context.registerVariable(new sys_var_bool_ptr("enable", &sysvar_logging_query_enable));
302
 
    context.registerVariable(new sys_var_const_string_val("filename", vm["filename"].as<string>()));
303
 
    context.registerVariable(new sys_var_const_string_val("pcre", vm["pcre"].as<string>()));
304
 
    context.registerVariable(new sys_var_constrained_value<uint32_t>("threshold_slow", sysvar_logging_query_threshold_slow));
305
 
    context.registerVariable(new sys_var_constrained_value<uint32_t>("threshold_big_resultset", sysvar_logging_query_threshold_big_resultset));
306
 
    context.registerVariable(new sys_var_constrained_value<uint32_t>("threshold_big_examined", sysvar_logging_query_threshold_big_examined));
307
 
  }
 
305
  handler= new Logging_query();
 
306
  context.add(handler);
308
307
 
309
308
  return 0;
310
309
}
311
310
 
312
 
static void init_options(drizzled::module::option_context &context)
313
 
{
314
 
  context("enable",
315
 
          po::value<bool>(&sysvar_logging_query_enable)->default_value(false)->zero_tokens(),
316
 
          _("Enable logging to CSV file"));
317
 
  context("filename",
318
 
          po::value<string>(),
319
 
          _("File to log to"));
320
 
  context("pcre",
321
 
          po::value<string>()->default_value(""),
322
 
          _("PCRE to match the query against"));
323
 
  context("threshold-slow",
324
 
          po::value<uint32_constraint>(&sysvar_logging_query_threshold_slow)->default_value(0),
325
 
          _("Threshold for logging slow queries, in microseconds"));
326
 
  context("threshold-big-resultset",
327
 
          po::value<uint32_constraint>(&sysvar_logging_query_threshold_big_resultset)->default_value(0),
328
 
          _("Threshold for logging big queries, for rows returned"));
329
 
  context("threshold-big-examined",
330
 
          po::value<uint32_constraint>(&sysvar_logging_query_threshold_big_examined)->default_value(0),
331
 
          _("Threshold for logging big queries, for rows examined"));
332
 
}
333
 
 
334
 
} /* namespace drizzle_plugin */
 
311
static DRIZZLE_SYSVAR_BOOL(
 
312
  enable,
 
313
  sysvar_logging_query_enable,
 
314
  PLUGIN_VAR_NOCMDARG,
 
315
  N_("Enable logging to CSV file"),
 
316
  NULL, /* check func */
 
317
  NULL, /* update func */
 
318
  false /* default */);
 
319
 
 
320
static DRIZZLE_SYSVAR_STR(
 
321
  filename,
 
322
  sysvar_logging_query_filename,
 
323
  PLUGIN_VAR_READONLY,
 
324
  N_("File to log to"),
 
325
  NULL, /* check func */
 
326
  NULL, /* update func*/
 
327
  NULL /* default */);
 
328
 
 
329
static DRIZZLE_SYSVAR_STR(
 
330
  pcre,
 
331
  sysvar_logging_query_pcre,
 
332
  PLUGIN_VAR_READONLY,
 
333
  N_("PCRE to match the query against"),
 
334
  NULL, /* check func */
 
335
  NULL, /* update func*/
 
336
  NULL /* default */);
 
337
 
 
338
static DRIZZLE_SYSVAR_ULONG(
 
339
  threshold_slow,
 
340
  sysvar_logging_query_threshold_slow,
 
341
  PLUGIN_VAR_OPCMDARG,
 
342
  N_("Threshold for logging slow queries, in microseconds"),
 
343
  NULL, /* check func */
 
344
  NULL, /* update func */
 
345
  0, /* default */
 
346
  0, /* min */
 
347
  UINT32_MAX, /* max */
 
348
  0 /* blksiz */);
 
349
 
 
350
static DRIZZLE_SYSVAR_ULONG(
 
351
  threshold_big_resultset,
 
352
  sysvar_logging_query_threshold_big_resultset,
 
353
  PLUGIN_VAR_OPCMDARG,
 
354
  N_("Threshold for logging big queries, for rows returned"),
 
355
  NULL, /* check func */
 
356
  NULL, /* update func */
 
357
  0, /* default */
 
358
  0, /* min */
 
359
  UINT32_MAX, /* max */
 
360
  0 /* blksiz */);
 
361
 
 
362
static DRIZZLE_SYSVAR_ULONG(
 
363
  threshold_big_examined,
 
364
  sysvar_logging_query_threshold_big_examined,
 
365
  PLUGIN_VAR_OPCMDARG,
 
366
  N_("Threshold for logging big queries, for rows examined"),
 
367
  NULL, /* check func */
 
368
  NULL, /* update func */
 
369
  0, /* default */
 
370
  0, /* min */
 
371
  UINT32_MAX, /* max */
 
372
  0 /* blksiz */);
 
373
 
 
374
static drizzle_sys_var* logging_query_system_variables[]= {
 
375
  DRIZZLE_SYSVAR(enable),
 
376
  DRIZZLE_SYSVAR(filename),
 
377
  DRIZZLE_SYSVAR(pcre),
 
378
  DRIZZLE_SYSVAR(threshold_slow),
 
379
  DRIZZLE_SYSVAR(threshold_big_resultset),
 
380
  DRIZZLE_SYSVAR(threshold_big_examined),
 
381
  NULL
 
382
};
335
383
 
336
384
DRIZZLE_DECLARE_PLUGIN
337
385
{
338
386
  DRIZZLE_VERSION_ID,
339
 
  "logging-query",
 
387
  "logging_query",
340
388
  "0.2",
341
389
  "Mark Atwood <mark@fallenpegasus.com>",
342
390
  N_("Log queries to a CSV file"),
343
391
  PLUGIN_LICENSE_GPL,
344
 
  drizzle_plugin::logging_query_plugin_init,
345
 
  NULL,
346
 
  drizzle_plugin::init_options
 
392
  logging_query_plugin_init,
 
393
  logging_query_system_variables,
 
394
  NULL
347
395
}
348
396
DRIZZLE_DECLARE_PLUGIN_END;