← Back to branch summary

~drizzle-trunk/drizzle/development

« back to all changes in this revision

Viewing changes to plugin/logging_query/logging_query.cc

pandora-build v0.72 - Moved remaining hard-coded tests into pandora-build
macros.
Add PANDORA_DRIZZLE_BUILD to run the extra checks that drizzle needs that 
plugins would also need to run so we can just use that macro in generated
external plugin builds.
Added support to register_plugins for external plugin building.
Renamed register_plugins.py to pandora-plugin.

Show diffs side-by-side

added added

removed removed

Lines of Context:
plugin/logging_query/logging_query.cc
 
1
/* -*- mode: c++; c-basic-offset: 2; indent-tabs-mode: nil; -*-
 
2
 *  vim:expandtab:shiftwidth=2:tabstop=2:smarttab:
 
3
 *
 
4
 *  Copyright (C) 2008,2009 Sun Microsystems
 
5
 *
 
6
 *  This program is free software; you can redistribute it and/or modify
 
7
 *  it under the terms of the GNU General Public License as published by
 
8
 *  the Free Software Foundation; version 2 of the License.
 
9
 *
 
10
 *  This program is distributed in the hope that it will be useful,
 
11
 *  but WITHOUT ANY WARRANTY; without even the implied warranty of
 
12
 *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 
13
 *  GNU General Public License for more details.
 
14
 *
 
15
 *  You should have received a copy of the GNU General Public License
 
16
 *  along with this program; if not, write to the Free Software
 
17
 *  Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA  02110-1301  USA
 
18
 */
 
19
 
 
20
#include <drizzled/server_includes.h>
 
21
#include <drizzled/plugin/logging.h>
 
22
#include <drizzled/gettext.h>
 
23
#include <drizzled/session.h>
 
24
#include PCRE_HEADER
 
25
 
 
26
/* TODO make this dynamic as needed */
 
27
static const int MAX_MSG_LEN= 32*1024;
 
28
 
 
29
static bool sysvar_logging_query_enable= false;
 
30
static char* sysvar_logging_query_filename= NULL;
 
31
static char* sysvar_logging_query_pcre= NULL;
 
32
/* TODO fix these to not be unsigned long once we have sensible sys_var system */
 
33
static unsigned long sysvar_logging_query_threshold_slow= 0;
 
34
static unsigned long sysvar_logging_query_threshold_big_resultset= 0;
 
35
static unsigned long sysvar_logging_query_threshold_big_examined= 0;
 
36
 
 
37
/* stolen from mysys/my_getsystime
 
38
   until the Session has a good utime "now" we can use
 
39
   will have to use this instead */
 
40
 
 
41
#include <sys/time.h>
 
42
static uint64_t get_microtime()
 
43
{
 
44
#if defined(HAVE_GETHRTIME)
 
45
  return gethrtime()/1000;
 
46
#else
 
47
  uint64_t newtime;
 
48
  struct timeval t;
 
49
  /*
 
50
    The following loop is here because gettimeofday may fail on some systems
 
51
  */
 
52
  while (gettimeofday(&t, NULL) != 0) {}
 
53
  newtime= (uint64_t)t.tv_sec * 1000000 + t.tv_usec;
 
54
  return newtime;
 
55
#endif  /* defined(HAVE_GETHRTIME) */
 
56
}
 
57
 
 
58
/* quote a string to be safe to include in a CSV line
 
59
   that means backslash quoting all commas, doublequotes, backslashes,
 
60
   and all the ASCII unprintable characters
 
61
   as long as we pass the high-bit bytes unchanged
 
62
   this is safe to do to a UTF8 string
 
63
   we dont allow overrunning the targetbuffer
 
64
   to avoid having a very long query overwrite memory
 
65
 
 
66
   TODO consider remapping the unprintables instead to "Printable
 
67
   Representation", the Unicode characters from the area U+2400 to
 
68
   U+2421 reserved for representing control characters when it is
 
69
   necessary to print or display them rather than have them perform
 
70
   their intended function.
 
71
 
 
72
*/
 
73
 
 
74
static unsigned char *quotify (const unsigned char *src, size_t srclen,
 
75
                               unsigned char *dst, size_t dstlen)
 
76
{
 
77
  static const char hexit[]= { '0', '1', '2', '3', '4', '5', '6', '7',
 
78
                          '8', '9', 'a', 'b', 'c', 'd', 'e', 'f' };
 
79
  size_t dst_ndx;  /* ndx down the dst */
 
80
  size_t src_ndx;  /* ndx down the src */
 
81
 
 
82
  assert(dst);
 
83
  assert(dstlen > 0);
 
84
 
 
85
  for (dst_ndx= 0,src_ndx= 0; src_ndx < srclen; src_ndx++)
 
86
  {
 
87
 
 
88
    /* Worst case, need 5 dst bytes for the next src byte.
 
89
       backslash x hexit hexit null
 
90
       so if not enough room, just terminate the string and return
 
91
    */
 
92
    if ((dstlen - dst_ndx) < 5)
 
93
    {
 
94
      dst[dst_ndx]= (unsigned char)0x00;
 
95
      return dst;
 
96
    }
 
97
 
 
98
    if (src[src_ndx] > 0x7f)
 
99
    {
 
100
      // pass thru high bit characters, they are non-ASCII UTF8 Unicode
 
101
      dst[dst_ndx++]= src[src_ndx];
 
102
    }
 
103
    else if (src[src_ndx] == 0x00)  // null
 
104
    {
 
105
      dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= (unsigned char) '0';
 
106
    }
 
107
    else if (src[src_ndx] == 0x07)  // bell
 
108
    {
 
109
      dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= (unsigned char) 'a';
 
110
    }
 
111
    else if (src[src_ndx] == 0x08)  // backspace
 
112
    {
 
113
      dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= (unsigned char) 'b';
 
114
    }
 
115
    else if (src[src_ndx] == 0x09)  // horiz tab
 
116
    {
 
117
      dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= (unsigned char) 't';
 
118
    }
 
119
    else if (src[src_ndx] == 0x0a)  // line feed
 
120
    {
 
121
      dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= (unsigned char) 'n';
 
122
    }
 
123
    else if (src[src_ndx] == 0x0b)  // vert tab
 
124
    {
 
125
      dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= (unsigned char) 'v';
 
126
    }
 
127
    else if (src[src_ndx] == 0x0c)  // formfeed
 
128
    {
 
129
      dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= (unsigned char) 'f';
 
130
    }
 
131
    else if (src[src_ndx] == 0x0d)  // carrage return
 
132
    {
 
133
      dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= (unsigned char) 'r';
 
134
    }
 
135
    else if (src[src_ndx] == 0x1b)  // escape
 
136
    {
 
137
      dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= (unsigned char) 'e';
 
138
    }
 
139
    else if (src[src_ndx] == 0x22)  // quotation mark
 
140
    {
 
141
      dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= 0x22;
 
142
    }
 
143
    else if (src[src_ndx] == 0x2C)  // comma
 
144
    {
 
145
      dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= 0x2C;
 
146
    }
 
147
    else if (src[src_ndx] == 0x5C)  // backslash
 
148
    {
 
149
      dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= 0x5C;
 
150
    }
 
151
    else if ((src[src_ndx] < 0x20) || (src[src_ndx] == 0x7F))  // other unprintable ASCII
 
152
    {
 
153
      dst[dst_ndx++]= 0x5C;
 
154
      dst[dst_ndx++]= (unsigned char) 'x';
 
155
      dst[dst_ndx++]= hexit[(src[src_ndx] >> 4) & 0x0f];
 
156
      dst[dst_ndx++]= hexit[src[src_ndx] & 0x0f];
 
157
    }
 
158
    else  // everything else
 
159
    {
 
160
      dst[dst_ndx++]= src[src_ndx];
 
161
    }
 
162
    dst[dst_ndx]= '\0';
 
163
  }
 
164
  return dst;
 
165
}
 
166
 
 
167
 
 
168
class Logging_query: public drizzled::plugin::Logging
 
169
{
 
170
  int fd;
 
171
  pcre *re;
 
172
  pcre_extra *pe;
 
173
 
 
174
public:
 
175
 
 
176
  Logging_query()
 
177
    : drizzled::plugin::Logging("Logging_query"),
 
178
      fd(-1), re(NULL), pe(NULL)
 
179
  {
 
180
 
 
181
    /* if there is no destination filename, dont bother doing anything */
 
182
    if (sysvar_logging_query_filename == NULL)
 
183
      return;
 
184
 
 
185
    fd= open(sysvar_logging_query_filename,
 
186
             O_WRONLY | O_APPEND | O_CREAT,
 
187
             S_IRUSR|S_IWUSR);
 
188
    if (fd < 0)
 
189
    {
 
190
      errmsg_printf(ERRMSG_LVL_ERROR, _("fail open() fn=%s er=%s\n"),
 
191
                    sysvar_logging_query_filename,
 
192
                    strerror(errno));
 
193
      return;
 
194
    }
 
195
 
 
196
    if (sysvar_logging_query_pcre != NULL)
 
197
    {
 
198
      const char *this_pcre_error;
 
199
      int this_pcre_erroffset;
 
200
      re= pcre_compile(sysvar_logging_query_pcre, 0, &this_pcre_error,
 
201
                       &this_pcre_erroffset, NULL);
 
202
      pe= pcre_study(re, 0, &this_pcre_error);
 
203
      /* TODO emit error messages if there is a problem */
 
204
    }
 
205
  }
 
206
 
 
207
  ~Logging_query()
 
208
  {
 
209
    if (fd >= 0)
 
210
    {
 
211
      close(fd);
 
212
    }
 
213
 
 
214
    if (pe != NULL)
 
215
    {
 
216
      pcre_free(pe);
 
217
    }
 
218
 
 
219
    if (re != NULL)
 
220
    {
 
221
      pcre_free(re);
 
222
    }
 
223
  }
 
224
 
 
225
 
 
226
  virtual bool pre (Session *)
 
227
  {
 
228
    /* we could just not have a pre entrypoint at all,
 
229
       and have logging_pre == NULL
 
230
       but we have this here for the sake of being an example */
 
231
    return false;
 
232
  }
 
233
 
 
234
  virtual bool post (Session *session)
 
235
  {
 
236
    char msgbuf[MAX_MSG_LEN];
 
237
    int msgbuf_len= 0;
 
238
    int wrv;
 
239
 
 
240
    assert(session != NULL);
 
241
 
 
242
    if (fd < 0)
 
243
      return false;
 
244
 
 
245
    /* Yes, we know that checking sysvar_logging_query_enable,
 
246
       sysvar_logging_query_threshold_big_resultset, and
 
247
       sysvar_logging_query_threshold_big_examined is not threadsafe,
 
248
       because some other thread might change these sysvars.  But we
 
249
       don't care.  We might start logging a little late as it spreads
 
250
       to other threads.  Big deal. */
 
251
 
 
252
    // return if not enabled or query was too fast or resultset was too small
 
253
    if (sysvar_logging_query_enable == false)
 
254
      return false;
 
255
    if (session->sent_row_count < sysvar_logging_query_threshold_big_resultset)
 
256
      return false;
 
257
    if (session->examined_row_count < sysvar_logging_query_threshold_big_examined)
 
258
      return false;
 
259
 
 
260
    /* TODO, the session object should have a "utime command completed"
 
261
       inside itself, so be more accurate, and so this doesnt have to
 
262
       keep calling current_utime, which can be slow */
 
263
  
 
264
    uint64_t t_mark= get_microtime();
 
265
  
 
266
    if ((t_mark - session->start_utime) < (sysvar_logging_query_threshold_slow))
 
267
      return false;
 
268
 
 
269
    if (re)
 
270
    {
 
271
      int this_pcre_rc;
 
272
      this_pcre_rc = pcre_exec(re, pe, session->query, session->query_length, 0, 0, NULL, 0);
 
273
      if (this_pcre_rc < 0)
 
274
        return false;
 
275
    }
 
276
 
 
277
    // buffer to quotify the query
 
278
    unsigned char qs[255];
 
279
  
 
280
    // to avoid trying to printf %s something that is potentially NULL
 
281
    const char *dbs= (session->db) ? session->db : "";
 
282
    int dbl= 0;
 
283
    if (dbs != NULL)
 
284
      dbl= session->db_length;
 
285
  
 
286
    msgbuf_len=
 
287
      snprintf(msgbuf, MAX_MSG_LEN,
 
288
               "%"PRIu64",%"PRIu64",%"PRIu64",\"%.*s\",\"%s\",\"%.*s\","
 
289
               "%"PRIu64",%"PRIu64",%"PRIu64",%"PRIu64",%"PRIu64","
 
290
               "%"PRIu32",%"PRIu32",%"PRIu32",\"%s\"\n",
 
291
               t_mark,
 
292
               session->thread_id,
 
293
               session->getQueryId(),
 
294
               // dont need to quote the db name, always CSV safe
 
295
               dbl, dbs,
 
296
               // do need to quote the query
 
297
               quotify((unsigned char *)session->getQueryString(),
 
298
                       session->getQueryLength(), qs, sizeof(qs)),
 
299
               // command_name is defined in drizzled/sql_parse.cc
 
300
               // dont need to quote the command name, always CSV safe
 
301
               (int)command_name[session->command].length,
 
302
               command_name[session->command].str,
 
303
               // counters are at end, to make it easier to add more
 
304
               (t_mark - session->getConnectMicroseconds()),
 
305
               (t_mark - session->start_utime),
 
306
               (t_mark - session->utime_after_lock),
 
307
               session->sent_row_count,
 
308
               session->examined_row_count,
 
309
               session->tmp_table,
 
310
               session->total_warn_count,
 
311
               session->getServerId(),
 
312
               glob_hostname
 
313
               );
 
314
  
 
315
    // a single write has a kernel thread lock, thus no need mutex guard this
 
316
    wrv= write(fd, msgbuf, msgbuf_len);
 
317
    assert(wrv == msgbuf_len);
 
318
  
 
319
    return false;
 
320
  }
 
321
};
 
322
 
 
323
static Logging_query *handler= NULL;
 
324
 
 
325
static int logging_query_plugin_init(drizzled::plugin::Registry &registry)
 
326
{
 
327
  handler= new Logging_query();
 
328
  registry.add(handler);
 
329
 
 
330
  return 0;
 
331
}
 
332
 
 
333
static int logging_query_plugin_deinit(drizzled::plugin::Registry &registry)
 
334
{
 
335
  registry.remove(handler);
 
336
  delete handler;
 
337
 
 
338
  return 0;
 
339
}
 
340
 
 
341
static DRIZZLE_SYSVAR_BOOL(
 
342
  enable,
 
343
  sysvar_logging_query_enable,
 
344
  PLUGIN_VAR_NOCMDARG,
 
345
  N_("Enable logging to CSV file"),
 
346
  NULL, /* check func */
 
347
  NULL, /* update func */
 
348
  false /* default */);
 
349
 
 
350
static DRIZZLE_SYSVAR_STR(
 
351
  filename,
 
352
  sysvar_logging_query_filename,
 
353
  PLUGIN_VAR_READONLY,
 
354
  N_("File to log to"),
 
355
  NULL, /* check func */
 
356
  NULL, /* update func*/
 
357
  NULL /* default */);
 
358
 
 
359
static DRIZZLE_SYSVAR_STR(
 
360
  pcre,
 
361
  sysvar_logging_query_pcre,
 
362
  PLUGIN_VAR_READONLY,
 
363
  N_("PCRE to match the query against"),
 
364
  NULL, /* check func */
 
365
  NULL, /* update func*/
 
366
  NULL /* default */);
 
367
 
 
368
static DRIZZLE_SYSVAR_ULONG(
 
369
  threshold_slow,
 
370
  sysvar_logging_query_threshold_slow,
 
371
  PLUGIN_VAR_OPCMDARG,
 
372
  N_("Threshold for logging slow queries, in microseconds"),
 
373
  NULL, /* check func */
 
374
  NULL, /* update func */
 
375
  0, /* default */
 
376
  0, /* min */
 
377
  UINT32_MAX, /* max */
 
378
  0 /* blksiz */);
 
379
 
 
380
static DRIZZLE_SYSVAR_ULONG(
 
381
  threshold_big_resultset,
 
382
  sysvar_logging_query_threshold_big_resultset,
 
383
  PLUGIN_VAR_OPCMDARG,
 
384
  N_("Threshold for logging big queries, for rows returned"),
 
385
  NULL, /* check func */
 
386
  NULL, /* update func */
 
387
  0, /* default */
 
388
  0, /* min */
 
389
  UINT32_MAX, /* max */
 
390
  0 /* blksiz */);
 
391
 
 
392
static DRIZZLE_SYSVAR_ULONG(
 
393
  threshold_big_examined,
 
394
  sysvar_logging_query_threshold_big_examined,
 
395
  PLUGIN_VAR_OPCMDARG,
 
396
  N_("Threshold for logging big queries, for rows examined"),
 
397
  NULL, /* check func */
 
398
  NULL, /* update func */
 
399
  0, /* default */
 
400
  0, /* min */
 
401
  UINT32_MAX, /* max */
 
402
  0 /* blksiz */);
 
403
 
 
404
static struct st_mysql_sys_var* logging_query_system_variables[]= {
 
405
  DRIZZLE_SYSVAR(enable),
 
406
  DRIZZLE_SYSVAR(filename),
 
407
  DRIZZLE_SYSVAR(pcre),
 
408
  DRIZZLE_SYSVAR(threshold_slow),
 
409
  DRIZZLE_SYSVAR(threshold_big_resultset),
 
410
  DRIZZLE_SYSVAR(threshold_big_examined),
 
411
  NULL
 
412
};
 
413
 
 
414
drizzle_declare_plugin
 
415
{
 
416
  "logging_query",
 
417
  "0.2",
 
418
  "Mark Atwood <mark@fallenpegasus.com>",
 
419
  N_("Log queries to a CSV file"),
 
420
  PLUGIN_LICENSE_GPL,
 
421
  logging_query_plugin_init,
 
422
  logging_query_plugin_deinit,
 
423
  NULL,   /* status variables */
 
424
  logging_query_system_variables,
 
425
  NULL
 
426
}
 
427
drizzle_declare_plugin_end;