← 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: brian
  • Date: 2008-06-25 05:29:13 UTC
  • Revision ID: brian@localhost.localdomain-20080625052913-6upwo0jsrl4lnapl
clean slate

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