27
27
#include <sys/types.h>
28
28
#include <sys/stat.h>
31
#include <boost/format.hpp>
32
#include <boost/program_options.hpp>
33
#include <drizzled/module/option_map.h>
37
namespace po= boost::program_options;
38
32
using namespace drizzled;
41
#define ESCAPE_CHAR '\\'
42
#define SEPARATOR_CHAR ','
44
namespace drizzle_plugin
34
/* TODO make this dynamic as needed */
35
static const int MAX_MSG_LEN= 32*1024;
47
37
static bool sysvar_logging_query_enable= false;
38
static char* sysvar_logging_query_filename= NULL;
39
static char* sysvar_logging_query_pcre= NULL;
48
40
/* 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;
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;
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 */
49
static uint64_t get_microtime()
51
#if defined(HAVE_GETHRTIME)
52
return gethrtime()/1000;
57
The following loop is here because gettimeofday may fail on some systems
59
while (gettimeofday(&t, NULL) != 0) {}
60
newtime= (uint64_t)t.tv_sec * 1000000 + t.tv_usec;
62
#endif /* defined(HAVE_GETHRTIME) */
53
65
/* quote a string to be safe to include in a CSV line
54
66
that means backslash quoting all commas, doublequotes, backslashes,
69
static void quotify(const string &src, string &dst)
81
static unsigned char *quotify (const unsigned char *src, size_t srclen,
82
unsigned char *dst, size_t dstlen)
71
84
static const char hexit[]= { '0', '1', '2', '3', '4', '5', '6', '7',
72
85
'8', '9', 'a', 'b', 'c', 'd', 'e', 'f' };
73
string::const_iterator src_iter;
75
for (src_iter= src.begin(); src_iter < src.end(); ++src_iter)
86
size_t dst_ndx; /* ndx down the dst */
87
size_t src_ndx; /* ndx down the src */
92
for (dst_ndx= 0,src_ndx= 0; src_ndx < srclen; src_ndx++)
77
if (static_cast<unsigned char>(*src_iter) > 0x7f)
79
dst.push_back(*src_iter);
81
else if (*src_iter == 0x00) // null
83
dst.push_back(ESCAPE_CHAR); dst.push_back('0');
85
else if (*src_iter == 0x07) // bell
87
dst.push_back(ESCAPE_CHAR); dst.push_back('a');
89
else if (*src_iter == 0x08) // backspace
91
dst.push_back(ESCAPE_CHAR); dst.push_back('b');
93
else if (*src_iter == 0x09) // horiz tab
95
dst.push_back(ESCAPE_CHAR); dst.push_back('t');
97
else if (*src_iter == 0x0a) // line feed
99
dst.push_back(ESCAPE_CHAR); dst.push_back('n');
101
else if (*src_iter == 0x0b) // vert tab
103
dst.push_back(ESCAPE_CHAR); dst.push_back('v');
105
else if (*src_iter == 0x0c) // formfeed
107
dst.push_back(ESCAPE_CHAR); dst.push_back('f');
109
else if (*src_iter == 0x0d) // carrage return
111
dst.push_back(ESCAPE_CHAR); dst.push_back('r');
113
else if (*src_iter == 0x1b) // escape
115
dst.push_back(ESCAPE_CHAR); dst.push_back('e');
117
else if (*src_iter == 0x22) // quotation mark
119
dst.push_back(ESCAPE_CHAR); dst.push_back(0x22);
121
else if (*src_iter == SEPARATOR_CHAR)
123
dst.push_back(ESCAPE_CHAR); dst.push_back(SEPARATOR_CHAR);
125
else if (*src_iter == ESCAPE_CHAR)
127
dst.push_back(ESCAPE_CHAR); dst.push_back(ESCAPE_CHAR);
129
else if ((*src_iter < 0x20) || (*src_iter == 0x7F)) // other unprintable ASCII
131
dst.push_back(ESCAPE_CHAR);
133
dst.push_back(hexit[(*src_iter >> 4) & 0x0f]);
134
dst.push_back(hexit[*src_iter & 0x0f]);
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
99
if ((dstlen - dst_ndx) < 5)
101
dst[dst_ndx]= (unsigned char)0x00;
105
if (src[src_ndx] > 0x7f)
107
// pass thru high bit characters, they are non-ASCII UTF8 Unicode
108
dst[dst_ndx++]= src[src_ndx];
110
else if (src[src_ndx] == 0x00) // null
112
dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= (unsigned char) '0';
114
else if (src[src_ndx] == 0x07) // bell
116
dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= (unsigned char) 'a';
118
else if (src[src_ndx] == 0x08) // backspace
120
dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= (unsigned char) 'b';
122
else if (src[src_ndx] == 0x09) // horiz tab
124
dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= (unsigned char) 't';
126
else if (src[src_ndx] == 0x0a) // line feed
128
dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= (unsigned char) 'n';
130
else if (src[src_ndx] == 0x0b) // vert tab
132
dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= (unsigned char) 'v';
134
else if (src[src_ndx] == 0x0c) // formfeed
136
dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= (unsigned char) 'f';
138
else if (src[src_ndx] == 0x0d) // carrage return
140
dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= (unsigned char) 'r';
142
else if (src[src_ndx] == 0x1b) // escape
144
dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= (unsigned char) 'e';
146
else if (src[src_ndx] == 0x22) // quotation mark
148
dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= 0x22;
150
else if (src[src_ndx] == 0x2C) // comma
152
dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= 0x2C;
154
else if (src[src_ndx] == 0x5C) // backslash
156
dst[dst_ndx++]= 0x5C; dst[dst_ndx++]= 0x5C;
158
else if ((src[src_ndx] < 0x20) || (src[src_ndx] == 0x7F)) // other unprintable ASCII
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];
136
165
else // everything else
138
dst.push_back(*src_iter);
167
dst[dst_ndx++]= src[src_ndx];
144
175
class Logging_query: public drizzled::plugin::Logging
146
const std::string _filename;
147
const std::string _query_pcre;
152
/** Format of the output string */
153
boost::format formatter;
157
Logging_query(const std::string &filename,
158
const std::string &query_pcre) :
159
drizzled::plugin::Logging("Logging_query"),
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")
184
: drizzled::plugin::Logging("Logging_query"),
185
fd(-1), re(NULL), pe(NULL)
167
188
/* if there is no destination filename, dont bother doing anything */
168
if (_filename.empty())
189
if (sysvar_logging_query_filename == NULL)
171
fd= open(_filename.c_str(),
192
fd= open(sysvar_logging_query_filename,
172
193
O_WRONLY | O_APPEND | O_CREAT,
173
194
S_IRUSR|S_IWUSR);
177
sql_perror( _("fail open()"), _filename);
197
errmsg_printf(ERRMSG_LVL_ERROR, _("fail open() fn=%s er=%s\n"),
198
sysvar_logging_query_filename,
181
if (not _query_pcre.empty())
203
if (sysvar_logging_query_pcre != NULL)
183
205
const char *this_pcre_error;
184
206
int this_pcre_erroffset;
185
re= pcre_compile(_query_pcre.c_str(), 0, &this_pcre_error,
207
re= pcre_compile(sysvar_logging_query_pcre, 0, &this_pcre_error,
186
208
&this_pcre_erroffset, NULL);
187
209
pe= pcre_study(re, 0, &this_pcre_error);
188
210
/* TODO emit error messages if there is a problem */
226
259
// return if not enabled or query was too fast or resultset was too small
227
260
if (sysvar_logging_query_enable == false)
229
if (session->sent_row_count < sysvar_logging_query_threshold_big_resultset.get())
231
if (session->examined_row_count < sysvar_logging_query_threshold_big_examined.get())
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.
239
uint64_t t_mark= session->getCurrentTimestamp(false);
241
if (session->getElapsedTime() < (sysvar_logging_query_threshold_slow.get()))
244
Session::QueryString query_string(session->getQueryString());
262
if (session->sent_row_count < sysvar_logging_query_threshold_big_resultset)
264
if (session->examined_row_count < sysvar_logging_query_threshold_big_examined)
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 */
271
uint64_t t_mark= get_microtime();
273
if ((t_mark - session->start_utime) < (sysvar_logging_query_threshold_slow))
247
278
int this_pcre_rc;
248
this_pcre_rc= pcre_exec(re, pe, query_string->c_str(), query_string->length(), 0, 0, NULL, 0);
279
this_pcre_rc = pcre_exec(re, pe, session->query, session->query_length, 0, 0, NULL, 0);
249
280
if (this_pcre_rc < 0)
253
284
// buffer to quotify the query
256
// Since quotify() builds the quoted string incrementally, we can
257
// avoid some reallocating if we reserve some space up front.
258
qs.reserve(query_string->length());
260
quotify(*query_string, qs);
285
unsigned char qs[255];
262
287
// 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() : "";
268
% session->getQueryId()
271
% getCommandName(session->command)
272
% (t_mark - session->getConnectMicroseconds())
273
% session->getElapsedTime()
274
% (t_mark - session->utime_after_lock)
275
% session->sent_row_count
276
% session->examined_row_count
278
% session->total_warn_count
279
% session->getServerId()
282
string msgbuf= formatter.str();
288
const char *dbs= session->db.empty() ? "" : session->db.c_str();
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",
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(),
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,
314
session->total_warn_count,
315
session->getServerId(),
284
319
// a single write has a kernel thread lock, thus no need mutex guard this
285
wrv= write(fd, msgbuf.c_str(), msgbuf.length());
286
assert(wrv == msgbuf.length());
320
wrv= write(fd, msgbuf, msgbuf_len);
321
assert(wrv == msgbuf_len);
292
static int logging_query_plugin_init(drizzled::module::Context &context)
295
const module::option_map &vm= context.getOptions();
297
if (vm.count("filename") > 0)
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));
312
static void init_options(drizzled::module::option_context &context)
315
po::value<bool>(&sysvar_logging_query_enable)->default_value(false)->zero_tokens(),
316
_("Enable logging to CSV file"));
319
_("File to log to"));
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"));
334
} /* namespace drizzle_plugin */
327
static Logging_query *handler= NULL;
329
static int logging_query_plugin_init(drizzled::plugin::Registry ®istry)
331
handler= new Logging_query();
332
registry.add(handler);
337
static int logging_query_plugin_deinit(drizzled::plugin::Registry ®istry)
339
registry.remove(handler);
345
static DRIZZLE_SYSVAR_BOOL(
347
sysvar_logging_query_enable,
349
N_("Enable logging to CSV file"),
350
NULL, /* check func */
351
NULL, /* update func */
352
false /* default */);
354
static DRIZZLE_SYSVAR_STR(
356
sysvar_logging_query_filename,
358
N_("File to log to"),
359
NULL, /* check func */
360
NULL, /* update func*/
363
static DRIZZLE_SYSVAR_STR(
365
sysvar_logging_query_pcre,
367
N_("PCRE to match the query against"),
368
NULL, /* check func */
369
NULL, /* update func*/
372
static DRIZZLE_SYSVAR_ULONG(
374
sysvar_logging_query_threshold_slow,
376
N_("Threshold for logging slow queries, in microseconds"),
377
NULL, /* check func */
378
NULL, /* update func */
381
UINT32_MAX, /* max */
384
static DRIZZLE_SYSVAR_ULONG(
385
threshold_big_resultset,
386
sysvar_logging_query_threshold_big_resultset,
388
N_("Threshold for logging big queries, for rows returned"),
389
NULL, /* check func */
390
NULL, /* update func */
393
UINT32_MAX, /* max */
396
static DRIZZLE_SYSVAR_ULONG(
397
threshold_big_examined,
398
sysvar_logging_query_threshold_big_examined,
400
N_("Threshold for logging big queries, for rows examined"),
401
NULL, /* check func */
402
NULL, /* update func */
405
UINT32_MAX, /* max */
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),
336
418
DRIZZLE_DECLARE_PLUGIN
338
420
DRIZZLE_VERSION_ID,
341
423
"Mark Atwood <mark@fallenpegasus.com>",
342
424
N_("Log queries to a CSV file"),
343
425
PLUGIN_LICENSE_GPL,
344
drizzle_plugin::logging_query_plugin_init,
346
drizzle_plugin::init_options
426
logging_query_plugin_init,
427
logging_query_plugin_deinit,
428
NULL, /* status variables */
429
logging_query_system_variables,
348
432
DRIZZLE_DECLARE_PLUGIN_END;