← Back to branch summary

~drizzle-trunk/drizzle/development

« back to all changes in this revision

Viewing changes to plugin/logging_query/logging_query.cc

  • Committer: Prafulla Tekawade
  • Date: 2010-08-06 11:21:12 UTC
  • mto: (1711.1.21 build) (1725.1.1 build)
  • mto: This revision was merged to the branch mainline in revision 1714.
  • Revision ID: prafulla_t@users.sourceforge.net-20100806112112-7w5u0s3nx9u67nzt
Fix for Bug 586051

1. test_if_ref method which checks whether predicate is already evaluated
   due to ref/eq_ref access or not was incorrectly removing a predicate 
   that was not implicitly evaluated due to ref access (due to presence of filesort ?)
   It was field=NULL predicate.
   Such predicate should be kept and execution engine will filter out rows
   correctly. Removal of such predicate led to returning of rows which had
   NULL for join/predicate columns.
2. field COMP_OP NULL will always false for all fields except when COMP_OP
   is NULL-safe equality operator. Modified range optimizer to return zero
   row count in such cases.
   Query now does not even run. It returns zero result. As such Fix(1) is not
   required but we might hit that case in some other query (I have not tried it
   yet)
3. Fixed Field::val_str to print "NULL" for literal NULL instead of "0". It
   added lot of confusion while debugging.

Show diffs side-by-side

added added

removed removed

Lines of Context:
plugin/logging_query/logging_query.cc
32
32
#include <boost/program_options.hpp>
33
33
#include <drizzled/module/option_map.h>
34
34
#include <cstdio>
35
 
#include <cerrno>
36
35
 
37
36
namespace po= boost::program_options;
38
37
using namespace drizzled;
41
40
#define ESCAPE_CHAR      '\\'
42
41
#define SEPARATOR_CHAR   ','
43
42
 
44
 
namespace drizzle_plugin
45
 
{
46
 
 
47
43
static bool sysvar_logging_query_enable= false;
 
44
static char* sysvar_logging_query_filename= NULL;
 
45
static char* sysvar_logging_query_pcre= NULL;
48
46
/* 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;
 
47
static unsigned long sysvar_logging_query_threshold_slow= 0;
 
48
static unsigned long sysvar_logging_query_threshold_big_resultset= 0;
 
49
static unsigned long sysvar_logging_query_threshold_big_examined= 0;
 
50
 
 
51
/* stolen from mysys/my_getsystime
 
52
   until the Session has a good utime "now" we can use
 
53
   will have to use this instead */
 
54
 
 
55
static uint64_t get_microtime()
 
56
{
 
57
#if defined(HAVE_GETHRTIME)
 
58
  return gethrtime()/1000;
 
59
#else
 
60
  uint64_t newtime;
 
61
  struct timeval t;
 
62
  /*
 
63
    The following loop is here because gettimeofday may fail on some systems
 
64
  */
 
65
  while (gettimeofday(&t, NULL) != 0) {}
 
66
  newtime= (uint64_t)t.tv_sec * 1000000 + t.tv_usec;
 
67
  return newtime;
 
68
#endif  /* defined(HAVE_GETHRTIME) */
 
69
}
52
70
 
53
71
/* quote a string to be safe to include in a CSV line
54
72
   that means backslash quoting all commas, doublequotes, backslashes,
143
161
 
144
162
class Logging_query: public drizzled::plugin::Logging
145
163
{
146
 
  const std::string _filename;
147
 
  const std::string _query_pcre;
148
164
  int fd;
149
165
  pcre *re;
150
166
  pcre_extra *pe;
154
170
 
155
171
public:
156
172
 
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")
 
173
  Logging_query()
 
174
    : drizzled::plugin::Logging("Logging_query"),
 
175
      fd(-1), re(NULL), pe(NULL),
 
176
      formatter("%1%,%2%,%3%,\"%4%\",\"%5%\",\"%6%\",%7%,%8%,"
 
177
                "%9%,%10%,%11%,%12%,%13%,%14%,\"%15%\"\n")
165
178
  {
166
179
 
167
180
    /* if there is no destination filename, dont bother doing anything */
168
 
    if (_filename.empty())
 
181
    if (sysvar_logging_query_filename == NULL)
169
182
      return;
170
183
 
171
 
    fd= open(_filename.c_str(),
 
184
    fd= open(sysvar_logging_query_filename,
172
185
             O_WRONLY | O_APPEND | O_CREAT,
173
186
             S_IRUSR|S_IWUSR);
174
187
    if (fd < 0)
175
188
    {
176
 
      char errmsg[STRERROR_MAX];
177
 
      strerror_r(errno, errmsg, sizeof(errmsg));
178
189
      errmsg_printf(ERRMSG_LVL_ERROR, _("fail open() fn=%s er=%s\n"),
179
 
                    _filename.c_str(),
180
 
                    errmsg);
 
190
                    sysvar_logging_query_filename,
 
191
                    strerror(errno));
181
192
      return;
182
193
    }
183
194
 
184
 
    if (not _query_pcre.empty())
 
195
    if (sysvar_logging_query_pcre != NULL)
185
196
    {
186
197
      const char *this_pcre_error;
187
198
      int this_pcre_erroffset;
188
 
      re= pcre_compile(_query_pcre.c_str(), 0, &this_pcre_error,
 
199
      re= pcre_compile(sysvar_logging_query_pcre, 0, &this_pcre_error,
189
200
                       &this_pcre_erroffset, NULL);
190
201
      pe= pcre_study(re, 0, &this_pcre_error);
191
202
      /* TODO emit error messages if there is a problem */
229
240
    // return if not enabled or query was too fast or resultset was too small
230
241
    if (sysvar_logging_query_enable == false)
231
242
      return false;
232
 
    if (session->sent_row_count < sysvar_logging_query_threshold_big_resultset.get())
 
243
    if (session->sent_row_count < sysvar_logging_query_threshold_big_resultset)
233
244
      return false;
234
 
    if (session->examined_row_count < sysvar_logging_query_threshold_big_examined.get())
 
245
    if (session->examined_row_count < sysvar_logging_query_threshold_big_examined)
235
246
      return false;
236
247
 
237
248
    /* TODO, the session object should have a "utime command completed"
238
249
       inside itself, so be more accurate, and so this doesnt have to
239
250
       keep calling current_utime, which can be slow */
240
251
  
241
 
    boost::posix_time::ptime mytime(boost::posix_time::microsec_clock::local_time());
242
 
    boost::posix_time::ptime epoch(boost::gregorian::date(1970,1,1));
243
 
    uint64_t t_mark= (mytime-epoch).total_microseconds();
244
 
 
245
 
    if ((t_mark - session->start_utime) < (sysvar_logging_query_threshold_slow.get()))
 
252
    uint64_t t_mark= get_microtime();
 
253
  
 
254
    if ((t_mark - session->start_utime) < (sysvar_logging_query_threshold_slow))
246
255
      return false;
247
256
 
248
 
    Session::QueryString query_string(session->getQueryString());
249
257
    if (re)
250
258
    {
251
259
      int this_pcre_rc;
252
 
      this_pcre_rc= pcre_exec(re, pe, query_string->c_str(), query_string->length(), 0, 0, NULL, 0);
 
260
      this_pcre_rc= pcre_exec(re, pe, session->query.c_str(), session->query.length(), 0, 0, NULL, 0);
253
261
      if (this_pcre_rc < 0)
254
262
        return false;
255
263
    }
259
267
    
260
268
    // Since quotify() builds the quoted string incrementally, we can
261
269
    // avoid some reallocating if we reserve some space up front.
262
 
    qs.reserve(query_string->length());
 
270
    qs.reserve(session->getQueryLength());
263
271
    
264
 
    quotify(*query_string, qs);
 
272
    quotify(session->getQueryString(), qs);
265
273
    
266
274
    // to avoid trying to printf %s something that is potentially NULL
267
 
    util::string::const_shared_ptr schema(session->schema());
268
 
    const char *dbs= (schema and not schema->empty()) ? schema->c_str() : "";
 
275
    const char *dbs= session->db.empty() ? "" : session->db.c_str();
269
276
 
270
277
    formatter % t_mark
271
278
              % session->thread_id
293
300
  }
294
301
};
295
302
 
 
303
static Logging_query *handler= NULL;
 
304
 
296
305
static int logging_query_plugin_init(drizzled::module::Context &context)
297
306
{
298
307
 
299
308
  const module::option_map &vm= context.getOptions();
300
 
 
301
 
  if (vm.count("filename") > 0)
302
 
  {
303
 
    context.add(new Logging_query(vm["filename"].as<string>(),
304
 
                                  vm["pcre"].as<string>()));
305
 
    context.registerVariable(new sys_var_bool_ptr("enable", &sysvar_logging_query_enable));
306
 
    context.registerVariable(new sys_var_const_string_val("filename", vm["filename"].as<string>()));
307
 
    context.registerVariable(new sys_var_const_string_val("pcre", vm["pcre"].as<string>()));
308
 
    context.registerVariable(new sys_var_constrained_value<uint32_t>("threshold_slow", sysvar_logging_query_threshold_slow));
309
 
    context.registerVariable(new sys_var_constrained_value<uint32_t>("threshold_big_resultset", sysvar_logging_query_threshold_big_resultset));
310
 
    context.registerVariable(new sys_var_constrained_value<uint32_t>("threshold_big_examined", sysvar_logging_query_threshold_big_examined));
311
 
  }
 
309
  if (vm.count("threshold-slow"))
 
310
  {
 
311
    if (sysvar_logging_query_threshold_slow > UINT32_MAX)
 
312
    {
 
313
      errmsg_printf(ERRMSG_LVL_ERROR, _("Invalid value for threshold-slow"));
 
314
      exit(-1);
 
315
    }
 
316
  }
 
317
 
 
318
  if (vm.count("threshold-big-resultset"))
 
319
  {
 
320
    if (sysvar_logging_query_threshold_big_resultset > UINT32_MAX)
 
321
    {
 
322
      errmsg_printf(ERRMSG_LVL_ERROR, _("Invalid value for threshold-big-resultset"));
 
323
      exit(-1);
 
324
    }
 
325
  }
 
326
 
 
327
  if (vm.count("threshold-big-examined"))
 
328
  {
 
329
    if (sysvar_logging_query_threshold_big_examined > UINT32_MAX)
 
330
    {
 
331
      errmsg_printf(ERRMSG_LVL_ERROR, _("Invalid value for threshold-big-examined"));
 
332
      exit(-1);
 
333
    }
 
334
  }
 
335
  handler= new Logging_query();
 
336
  context.add(handler);
312
337
 
313
338
  return 0;
314
339
}
318
343
  context("enable",
319
344
          po::value<bool>(&sysvar_logging_query_enable)->default_value(false)->zero_tokens(),
320
345
          N_("Enable logging to CSV file"));
321
 
  context("filename",
322
 
          po::value<string>(),
323
 
          N_("File to log to"));
324
 
  context("pcre",
325
 
          po::value<string>()->default_value(""),
326
 
          N_("PCRE to match the query against"));
327
346
  context("threshold-slow",
328
 
          po::value<uint32_constraint>(&sysvar_logging_query_threshold_slow)->default_value(0),
 
347
          po::value<unsigned long>(&sysvar_logging_query_threshold_slow)->default_value(0),
329
348
          N_("Threshold for logging slow queries, in microseconds"));
330
349
  context("threshold-big-resultset",
331
 
          po::value<uint32_constraint>(&sysvar_logging_query_threshold_big_resultset)->default_value(0),
 
350
          po::value<unsigned long>(&sysvar_logging_query_threshold_big_resultset)->default_value(0),
332
351
          N_("Threshold for logging big queries, for rows returned"));
333
352
  context("threshold-big-examined",
334
 
          po::value<uint32_constraint>(&sysvar_logging_query_threshold_big_examined)->default_value(0),
 
353
          po::value<unsigned long>(&sysvar_logging_query_threshold_big_examined)->default_value(0),
335
354
          N_("Threshold for logging big queries, for rows examined"));
336
355
}
337
356
 
338
 
} /* namespace drizzle_plugin */
 
357
static DRIZZLE_SYSVAR_BOOL(
 
358
  enable,
 
359
  sysvar_logging_query_enable,
 
360
  PLUGIN_VAR_NOCMDARG,
 
361
  N_("Enable logging to CSV file"),
 
362
  NULL, /* check func */
 
363
  NULL, /* update func */
 
364
  false /* default */);
 
365
 
 
366
static DRIZZLE_SYSVAR_STR(
 
367
  filename,
 
368
  sysvar_logging_query_filename,
 
369
  PLUGIN_VAR_READONLY,
 
370
  N_("File to log to"),
 
371
  NULL, /* check func */
 
372
  NULL, /* update func*/
 
373
  NULL /* default */);
 
374
 
 
375
static DRIZZLE_SYSVAR_STR(
 
376
  pcre,
 
377
  sysvar_logging_query_pcre,
 
378
  PLUGIN_VAR_READONLY,
 
379
  N_("PCRE to match the query against"),
 
380
  NULL, /* check func */
 
381
  NULL, /* update func*/
 
382
  NULL /* default */);
 
383
 
 
384
static DRIZZLE_SYSVAR_ULONG(
 
385
  threshold_slow,
 
386
  sysvar_logging_query_threshold_slow,
 
387
  PLUGIN_VAR_OPCMDARG,
 
388
  N_("Threshold for logging slow queries, in microseconds"),
 
389
  NULL, /* check func */
 
390
  NULL, /* update func */
 
391
  0, /* default */
 
392
  0, /* min */
 
393
  UINT32_MAX, /* max */
 
394
  0 /* blksiz */);
 
395
 
 
396
static DRIZZLE_SYSVAR_ULONG(
 
397
  threshold_big_resultset,
 
398
  sysvar_logging_query_threshold_big_resultset,
 
399
  PLUGIN_VAR_OPCMDARG,
 
400
  N_("Threshold for logging big queries, for rows returned"),
 
401
  NULL, /* check func */
 
402
  NULL, /* update func */
 
403
  0, /* default */
 
404
  0, /* min */
 
405
  UINT32_MAX, /* max */
 
406
  0 /* blksiz */);
 
407
 
 
408
static DRIZZLE_SYSVAR_ULONG(
 
409
  threshold_big_examined,
 
410
  sysvar_logging_query_threshold_big_examined,
 
411
  PLUGIN_VAR_OPCMDARG,
 
412
  N_("Threshold for logging big queries, for rows examined"),
 
413
  NULL, /* check func */
 
414
  NULL, /* update func */
 
415
  0, /* default */
 
416
  0, /* min */
 
417
  UINT32_MAX, /* max */
 
418
  0 /* blksiz */);
 
419
 
 
420
static drizzle_sys_var* logging_query_system_variables[]= {
 
421
  DRIZZLE_SYSVAR(enable),
 
422
  DRIZZLE_SYSVAR(filename),
 
423
  DRIZZLE_SYSVAR(pcre),
 
424
  DRIZZLE_SYSVAR(threshold_slow),
 
425
  DRIZZLE_SYSVAR(threshold_big_resultset),
 
426
  DRIZZLE_SYSVAR(threshold_big_examined),
 
427
  NULL
 
428
};
339
429
 
340
430
DRIZZLE_DECLARE_PLUGIN
341
431
{
345
435
  "Mark Atwood <mark@fallenpegasus.com>",
346
436
  N_("Log queries to a CSV file"),
347
437
  PLUGIN_LICENSE_GPL,
348
 
  drizzle_plugin::logging_query_plugin_init,
349
 
  NULL,
350
 
  drizzle_plugin::init_options
 
438
  logging_query_plugin_init,
 
439
  logging_query_system_variables,
 
440
  init_options
351
441
}
352
442
DRIZZLE_DECLARE_PLUGIN_END;