1
/* -*- mode: c++; c-basic-offset: 2; indent-tabs-mode: nil; -*-
2
* vim:expandtab:shiftwidth=2:tabstop=2:smarttab:
4
* Copyright (C) 2008,2009 Sun Microsystems
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.
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.
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
21
#include <drizzled/plugin/logging.h>
22
#include <drizzled/gettext.h>
23
#include <drizzled/session.h>
27
#include <sys/types.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
using namespace drizzled;
41
#define ESCAPE_CHAR '\\'
42
#define SEPARATOR_CHAR ','
44
namespace drizzle_plugin
47
static bool sysvar_logging_query_enable= false;
48
/* 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;
53
/* quote a string to be safe to include in a CSV line
54
that means backslash quoting all commas, doublequotes, backslashes,
55
and all the ASCII unprintable characters
56
as long as we pass the high-bit bytes unchanged
57
this is safe to do to a UTF8 string
58
we dont allow overrunning the targetbuffer
59
to avoid having a very long query overwrite memory
61
TODO consider remapping the unprintables instead to "Printable
62
Representation", the Unicode characters from the area U+2400 to
63
U+2421 reserved for representing control characters when it is
64
necessary to print or display them rather than have them perform
65
their intended function.
69
static void quotify(const string &src, string &dst)
71
static const char hexit[]= { '0', '1', '2', '3', '4', '5', '6', '7',
72
'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)
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]);
136
else // everything else
138
dst.push_back(*src_iter);
144
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")
167
/* if there is no destination filename, dont bother doing anything */
168
if (_filename.empty())
171
fd= open(_filename.c_str(),
172
O_WRONLY | O_APPEND | O_CREAT,
176
char errmsg[STRERROR_MAX];
177
strerror_r(errno, errmsg, sizeof(errmsg));
178
errmsg_printf(ERRMSG_LVL_ERROR, _("fail open() fn=%s er=%s\n"),
184
if (not _query_pcre.empty())
186
const char *this_pcre_error;
187
int this_pcre_erroffset;
188
re= pcre_compile(_query_pcre.c_str(), 0, &this_pcre_error,
189
&this_pcre_erroffset, NULL);
190
pe= pcre_study(re, 0, &this_pcre_error);
191
/* TODO emit error messages if there is a problem */
213
virtual bool post (Session *session)
217
assert(session != NULL);
222
/* Yes, we know that checking sysvar_logging_query_enable,
223
sysvar_logging_query_threshold_big_resultset, and
224
sysvar_logging_query_threshold_big_examined is not threadsafe,
225
because some other thread might change these sysvars. But we
226
don't care. We might start logging a little late as it spreads
227
to other threads. Big deal. */
229
// return if not enabled or query was too fast or resultset was too small
230
if (sysvar_logging_query_enable == false)
232
if (session->sent_row_count < sysvar_logging_query_threshold_big_resultset.get())
234
if (session->examined_row_count < sysvar_logging_query_threshold_big_examined.get())
237
/* TODO, the session object should have a "utime command completed"
238
inside itself, so be more accurate, and so this doesnt have to
239
keep calling current_utime, which can be slow */
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();
245
if ((t_mark - session->start_utime) < (sysvar_logging_query_threshold_slow.get()))
248
Session::QueryString query_string(session->getQueryString());
252
this_pcre_rc= pcre_exec(re, pe, query_string->c_str(), query_string->length(), 0, 0, NULL, 0);
253
if (this_pcre_rc < 0)
257
// buffer to quotify the query
260
// Since quotify() builds the quoted string incrementally, we can
261
// avoid some reallocating if we reserve some space up front.
262
qs.reserve(query_string->length());
264
quotify(*query_string, qs);
266
// 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() : "";
272
% session->getQueryId()
275
% command_name[session->command].str
276
% (t_mark - session->getConnectMicroseconds())
277
% (t_mark - session->start_utime)
278
% (t_mark - session->utime_after_lock)
279
% session->sent_row_count
280
% session->examined_row_count
282
% session->total_warn_count
283
% session->getServerId()
286
string msgbuf= formatter.str();
288
// a single write has a kernel thread lock, thus no need mutex guard this
289
wrv= write(fd, msgbuf.c_str(), msgbuf.length());
290
assert(wrv == msgbuf.length());
1
/* drizzle/plugin/logging_query/logging_query.cc */
3
/* need to define DRIZZLE_SERVER to get inside the THD */
4
#define DRIZZLE_SERVER 1
5
#include <drizzled/server_includes.h>
6
#include <drizzled/plugin_logging.h>
8
#define MAX_MSG_LEN (32*1024)
10
static char* logging_query_filename= NULL;
14
// copied from drizzled/sql_parse.cc
16
const LEX_STRING command_name[]={
17
{ C_STRING_WITH_LEN("Sleep") },
18
{ C_STRING_WITH_LEN("Quit") },
19
{ C_STRING_WITH_LEN("InitDB") },
20
{ C_STRING_WITH_LEN("Query") },
21
{ C_STRING_WITH_LEN("FieldList") },
22
{ C_STRING_WITH_LEN("CreateDB") },
23
{ C_STRING_WITH_LEN("DropDB") },
24
{ C_STRING_WITH_LEN("Refresh") },
25
{ C_STRING_WITH_LEN("Shutdown") },
26
{ C_STRING_WITH_LEN("Processlist") },
27
{ C_STRING_WITH_LEN("Connect") },
28
{ C_STRING_WITH_LEN("Kill") },
29
{ C_STRING_WITH_LEN("Ping") },
30
{ C_STRING_WITH_LEN("Time") },
31
{ C_STRING_WITH_LEN("ChangeUser") },
32
{ C_STRING_WITH_LEN("BinlogDump") },
33
{ C_STRING_WITH_LEN("ConnectOut") },
34
{ C_STRING_WITH_LEN("RegisterSlave") },
35
{ C_STRING_WITH_LEN("SetOption") },
36
{ C_STRING_WITH_LEN("Daemon") },
37
{ C_STRING_WITH_LEN("Error") }
41
bool logging_query_func_pre (THD *thd)
43
char msgbuf[MAX_MSG_LEN];
53
snprintf(msgbuf, MAX_MSG_LEN,
54
"log bgn thread_id=%ld query_id=%ld command=%.*s"
55
" db=\"%.*s\" query=\"%.*s\"\n",
56
(unsigned long) thd->thread_id,
57
(unsigned long) thd->query_id,
58
(uint32_t)command_name[thd->command].length, command_name[thd->command].str,
59
thd->db_length, thd->db,
60
thd->query_length, thd->query);
61
/* a single write has a OS level thread lock
62
so there is no need to have mutexes guarding this write,
64
wrv= write(fd, msgbuf, msgbuf_len);
65
assert(wrv == msgbuf_len);
70
bool logging_query_func_post (THD *thd)
72
char msgbuf[MAX_MSG_LEN];
76
if (fd < 0) return false;
81
snprintf(msgbuf, MAX_MSG_LEN,
82
"log end thread_id=%ld query_id=%ld command=%.*s"
83
" rows.sent=%ld rows.exam=%u\n",
84
(unsigned long) thd->thread_id,
85
(unsigned long) thd->query_id,
86
(uint32_t)command_name[thd->command].length, command_name[thd->command].str,
87
(unsigned long) thd->sent_row_count,
88
(uint32_t) thd->examined_row_count);
89
/* a single write has a OS level thread lock
90
so there is no need to have mutexes guarding this write,
92
wrv= write(fd, msgbuf, msgbuf_len);
93
assert(wrv == msgbuf_len);
99
static int logging_query_plugin_init(void *p)
101
logging_t *l= (logging_t *) p;
103
if (logging_query_filename == NULL)
105
/* no destination filename was specified via system variables
106
return now, dont set the callback pointers
111
fd= open(logging_query_filename, O_WRONLY | O_APPEND | O_CREAT);
114
fprintf(stderr, "fail open fn=%s er=%s\n",
115
logging_query_filename,
118
/* we should return an error here, so the plugin doesnt load
119
but this causes Drizzle to crash
120
so until that is fixed,
121
just return a success,
122
but leave the function pointers as NULL and the fd as -1
127
l->logging_pre= logging_query_func_pre;
128
l->logging_post= logging_query_func_post;
133
static int logging_query_plugin_deinit(void *p)
135
logging_st *l= (logging_st *) p;
143
l->logging_pre= NULL;
144
l->logging_post= NULL;
149
static DRIZZLE_SYSVAR_STR(filename, logging_query_filename,
151
"File to log queries to.",
154
static struct st_mysql_sys_var* logging_query_system_variables[]= {
155
DRIZZLE_SYSVAR(filename),
296
static int logging_query_plugin_init(drizzled::module::Context &context)
299
const module::option_map &vm= context.getOptions();
301
if (vm.count("filename") > 0)
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));
316
static void init_options(drizzled::module::option_context &context)
319
po::value<bool>(&sysvar_logging_query_enable)->default_value(false)->zero_tokens(),
320
N_("Enable logging to CSV file"));
323
N_("File to log to"));
325
po::value<string>()->default_value(""),
326
N_("PCRE to match the query against"));
327
context("threshold-slow",
328
po::value<uint32_constraint>(&sysvar_logging_query_threshold_slow)->default_value(0),
329
N_("Threshold for logging slow queries, in microseconds"));
330
context("threshold-big-resultset",
331
po::value<uint32_constraint>(&sysvar_logging_query_threshold_big_resultset)->default_value(0),
332
N_("Threshold for logging big queries, for rows returned"));
333
context("threshold-big-examined",
334
po::value<uint32_constraint>(&sysvar_logging_query_threshold_big_examined)->default_value(0),
335
N_("Threshold for logging big queries, for rows examined"));
338
} /* namespace drizzle_plugin */
340
DRIZZLE_DECLARE_PLUGIN
159
mysql_declare_plugin(logging_query)
161
DRIZZLE_LOGGER_PLUGIN,
345
164
"Mark Atwood <mark@fallenpegasus.com>",
346
N_("Log queries to a CSV file"),
347
166
PLUGIN_LICENSE_GPL,
348
drizzle_plugin::logging_query_plugin_init,
350
drizzle_plugin::init_options
167
logging_query_plugin_init,
168
logging_query_plugin_deinit,
169
NULL, /* status variables */
170
logging_query_system_variables,
352
DRIZZLE_DECLARE_PLUGIN_END;
173
mysql_declare_plugin_end;