~drizzle-trunk/drizzle/development

« back to all changes in this revision

Viewing changes to plugin/logging_query/logging_query.cc

  • Committer: Monty Taylor
  • Date: 2008-10-09 22:38:27 UTC
  • mto: This revision was merged to the branch mainline in revision 497.
  • Revision ID: monty@inaugust.com-20081009223827-bc9gvpiplsmvpwyq
Moved test() to its own file.
Made a new function to possibly replace int10_to_str.

Show diffs side-by-side

added added

removed removed

Lines of Context:
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
 
#include <string>
31
 
#include <boost/format.hpp>
32
 
#include <boost/program_options.hpp>
33
 
#include <drizzled/module/option_map.h>
34
 
#include <cstdio>
35
 
#include <cerrno>
36
 
 
37
 
namespace po= boost::program_options;
38
 
using namespace drizzled;
39
 
using namespace std;
40
 
 
41
 
#define ESCAPE_CHAR      '\\'
42
 
#define SEPARATOR_CHAR   ','
43
 
 
44
 
namespace drizzle_plugin
45
 
{
46
 
 
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;
52
 
 
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
60
 
 
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.
66
 
 
67
 
*/
68
 
 
69
 
static void quotify(const string &src, string &dst)
70
 
{
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;
74
 
  
75
 
  for (src_iter= src.begin(); src_iter < src.end(); ++src_iter)
76
 
  {
77
 
    if (static_cast<unsigned char>(*src_iter) > 0x7f)
78
 
    {
79
 
      dst.push_back(*src_iter);
80
 
    }
81
 
    else if (*src_iter == 0x00)  // null
82
 
    {
83
 
      dst.push_back(ESCAPE_CHAR); dst.push_back('0');
84
 
    }
85
 
    else if (*src_iter == 0x07)  // bell
86
 
    {
87
 
      dst.push_back(ESCAPE_CHAR); dst.push_back('a');
88
 
    }
89
 
    else if (*src_iter == 0x08)  // backspace
90
 
    {
91
 
      dst.push_back(ESCAPE_CHAR); dst.push_back('b');
92
 
    }
93
 
    else if (*src_iter == 0x09)  // horiz tab
94
 
    {
95
 
      dst.push_back(ESCAPE_CHAR); dst.push_back('t');
96
 
    }
97
 
    else if (*src_iter == 0x0a)  // line feed
98
 
    {
99
 
      dst.push_back(ESCAPE_CHAR); dst.push_back('n');
100
 
    }
101
 
    else if (*src_iter == 0x0b)  // vert tab
102
 
    {
103
 
      dst.push_back(ESCAPE_CHAR); dst.push_back('v');
104
 
    }
105
 
    else if (*src_iter == 0x0c)  // formfeed
106
 
    {
107
 
      dst.push_back(ESCAPE_CHAR); dst.push_back('f');
108
 
    }
109
 
    else if (*src_iter == 0x0d)  // carrage return
110
 
    {
111
 
      dst.push_back(ESCAPE_CHAR); dst.push_back('r');
112
 
    }
113
 
    else if (*src_iter == 0x1b)  // escape
114
 
    {
115
 
      dst.push_back(ESCAPE_CHAR); dst.push_back('e');
116
 
    }
117
 
    else if (*src_iter == 0x22)  // quotation mark
118
 
    {
119
 
      dst.push_back(ESCAPE_CHAR); dst.push_back(0x22);
120
 
    }
121
 
    else if (*src_iter == SEPARATOR_CHAR)
122
 
    {
123
 
      dst.push_back(ESCAPE_CHAR); dst.push_back(SEPARATOR_CHAR);
124
 
    }
125
 
    else if (*src_iter == ESCAPE_CHAR)
126
 
    {
127
 
      dst.push_back(ESCAPE_CHAR); dst.push_back(ESCAPE_CHAR);
128
 
    }
129
 
    else if ((*src_iter < 0x20) || (*src_iter == 0x7F))  // other unprintable ASCII
130
 
    {
131
 
      dst.push_back(ESCAPE_CHAR);
132
 
      dst.push_back('x');
133
 
      dst.push_back(hexit[(*src_iter >> 4) & 0x0f]);
134
 
      dst.push_back(hexit[*src_iter & 0x0f]);
135
 
    }
136
 
    else  // everything else
137
 
    {
138
 
      dst.push_back(*src_iter);
139
 
    }
140
 
  }
141
 
}
142
 
 
143
 
 
144
 
class Logging_query: public drizzled::plugin::Logging
145
 
{
146
 
  const std::string _filename;
147
 
  const std::string _query_pcre;
148
 
  int fd;
149
 
  pcre *re;
150
 
  pcre_extra *pe;
151
 
 
152
 
  /** Format of the output string */
153
 
  boost::format formatter;
154
 
 
155
 
public:
156
 
 
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")
165
 
  {
166
 
 
167
 
    /* if there is no destination filename, dont bother doing anything */
168
 
    if (_filename.empty())
169
 
      return;
170
 
 
171
 
    fd= open(_filename.c_str(),
172
 
             O_WRONLY | O_APPEND | O_CREAT,
173
 
             S_IRUSR|S_IWUSR);
174
 
    if (fd < 0)
175
 
    {
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"),
179
 
                    _filename.c_str(),
180
 
                    errmsg);
181
 
      return;
182
 
    }
183
 
 
184
 
    if (not _query_pcre.empty())
185
 
    {
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 */
192
 
    }
193
 
  }
194
 
 
195
 
  ~Logging_query()
196
 
  {
197
 
    if (fd >= 0)
198
 
    {
199
 
      close(fd);
200
 
    }
201
 
 
202
 
    if (pe != NULL)
203
 
    {
204
 
      pcre_free(pe);
205
 
    }
206
 
 
207
 
    if (re != NULL)
208
 
    {
209
 
      pcre_free(re);
210
 
    }
211
 
  }
212
 
 
213
 
  virtual bool post (Session *session)
214
 
  {
215
 
    size_t wrv;
216
 
 
217
 
    assert(session != NULL);
218
 
 
219
 
    if (fd < 0)
220
 
      return false;
221
 
 
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. */
228
 
 
229
 
    // return if not enabled or query was too fast or resultset was too small
230
 
    if (sysvar_logging_query_enable == false)
231
 
      return false;
232
 
    if (session->sent_row_count < sysvar_logging_query_threshold_big_resultset.get())
233
 
      return false;
234
 
    if (session->examined_row_count < sysvar_logging_query_threshold_big_examined.get())
235
 
      return false;
236
 
 
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 */
240
 
  
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()))
246
 
      return false;
247
 
 
248
 
    Session::QueryString query_string(session->getQueryString());
249
 
    if (re)
250
 
    {
251
 
      int this_pcre_rc;
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)
254
 
        return false;
255
 
    }
256
 
 
257
 
    // buffer to quotify the query
258
 
    string qs;
259
 
    
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());
263
 
    
264
 
    quotify(*query_string, qs);
265
 
    
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() : "";
269
 
 
270
 
    formatter % t_mark
271
 
              % session->thread_id
272
 
              % session->getQueryId()
273
 
              % dbs
274
 
              % qs
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
281
 
              % session->tmp_table
282
 
              % session->total_warn_count
283
 
              % session->getServerId()
284
 
              % glob_hostname;
285
 
 
286
 
    string msgbuf= formatter.str();
287
 
 
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());
291
 
 
 
1
/* drizzle/plugin/logging_query/logging_query.cc */
 
2
 
 
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>
 
7
 
 
8
#define MAX_MSG_LEN (32*1024)
 
9
 
 
10
static char* logging_query_filename= NULL;
 
11
 
 
12
static int fd= -1;
 
13
 
 
14
// copied from drizzled/sql_parse.cc
 
15
 
 
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") }
 
38
};
 
39
 
 
40
 
 
41
bool logging_query_func_pre (THD *thd)
 
42
{
 
43
  char msgbuf[MAX_MSG_LEN];
 
44
  int msgbuf_len= 0;
 
45
  int wrv;
 
46
 
 
47
  if (fd < 0) 
292
48
    return false;
293
 
  }
 
49
 
 
50
  assert(thd != NULL);
 
51
 
 
52
  msgbuf_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,
 
63
  */
 
64
  wrv= write(fd, msgbuf, msgbuf_len);
 
65
  assert(wrv == msgbuf_len);
 
66
 
 
67
  return false;
 
68
}
 
69
 
 
70
bool logging_query_func_post (THD *thd)
 
71
{
 
72
  char msgbuf[MAX_MSG_LEN];
 
73
  int msgbuf_len= 0;
 
74
  int wrv;
 
75
 
 
76
  if (fd < 0) return false;
 
77
 
 
78
  assert(thd != NULL);
 
79
 
 
80
  msgbuf_len=
 
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,
 
91
  */
 
92
  wrv= write(fd, msgbuf, msgbuf_len);
 
93
  assert(wrv == msgbuf_len);
 
94
 
 
95
 
 
96
  return false;
 
97
}
 
98
 
 
99
static int logging_query_plugin_init(void *p)
 
100
{
 
101
  logging_t *l= (logging_t *) p;
 
102
 
 
103
  if (logging_query_filename == NULL)
 
104
  {
 
105
    /* no destination filename was specified via system variables
 
106
       return now, dont set the callback pointers 
 
107
    */
 
108
    return 0;
 
109
  }
 
110
 
 
111
  fd= open(logging_query_filename, O_WRONLY | O_APPEND | O_CREAT);
 
112
  if (fd < 0) 
 
113
  {
 
114
    fprintf(stderr, "fail open fn=%s er=%s\n",
 
115
            logging_query_filename,
 
116
            strerror(errno));
 
117
 
 
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
 
123
    */
 
124
    return 0;
 
125
  }
 
126
 
 
127
  l->logging_pre= logging_query_func_pre;
 
128
  l->logging_post= logging_query_func_post;
 
129
 
 
130
  return 0;
 
131
}
 
132
 
 
133
static int logging_query_plugin_deinit(void *p)
 
134
{
 
135
  logging_st *l= (logging_st *) p;
 
136
 
 
137
  if (fd >= 0) 
 
138
  {
 
139
    close(fd);
 
140
    fd= -1;
 
141
  }
 
142
 
 
143
  l->logging_pre= NULL;
 
144
  l->logging_post= NULL;
 
145
 
 
146
  return 0;
 
147
}
 
148
 
 
149
static DRIZZLE_SYSVAR_STR(filename, logging_query_filename,
 
150
  PLUGIN_VAR_READONLY,
 
151
  "File to log queries to.",
 
152
  NULL, NULL, NULL);
 
153
 
 
154
static struct st_mysql_sys_var* logging_query_system_variables[]= {
 
155
  DRIZZLE_SYSVAR(filename),
 
156
  NULL
294
157
};
295
158
 
296
 
static int logging_query_plugin_init(drizzled::module::Context &context)
297
 
{
298
 
 
299
 
  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
 
  }
312
 
 
313
 
  return 0;
314
 
}
315
 
 
316
 
static void init_options(drizzled::module::option_context &context)
317
 
{
318
 
  context("enable",
319
 
          po::value<bool>(&sysvar_logging_query_enable)->default_value(false)->zero_tokens(),
320
 
          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
 
  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"));
336
 
}
337
 
 
338
 
} /* namespace drizzle_plugin */
339
 
 
340
 
DRIZZLE_DECLARE_PLUGIN
341
 
{
342
 
  DRIZZLE_VERSION_ID,
343
 
  "logging-query",
344
 
  "0.2",
 
159
mysql_declare_plugin(logging_query)
 
160
{
 
161
  DRIZZLE_LOGGER_PLUGIN,
 
162
  "logging_query",
 
163
  "0.1",
345
164
  "Mark Atwood <mark@fallenpegasus.com>",
346
 
  N_("Log queries to a CSV file"),
 
165
  "Log queries",
347
166
  PLUGIN_LICENSE_GPL,
348
 
  drizzle_plugin::logging_query_plugin_init,
349
 
  NULL,
350
 
  drizzle_plugin::init_options
 
167
  logging_query_plugin_init,
 
168
  logging_query_plugin_deinit,
 
169
  NULL,   /* status variables */
 
170
  logging_query_system_variables,
 
171
  NULL
351
172
}
352
 
DRIZZLE_DECLARE_PLUGIN_END;
 
173
mysql_declare_plugin_end;