~drizzle-trunk/drizzle/development

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
/* -*- mode: c++; c-basic-offset: 2; indent-tabs-mode: nil; -*-
 *  vim:expandtab:shiftwidth=2:tabstop=2:smarttab:
 *
 *  Copyright (C) 2009 Sun Microsystems
 *  Copyright (C) 2010 Mark Atwood
 *
 *  This program is free software; you can redistribute it and/or modify
 *  it under the terms of the GNU General Public License as published by
 *  the Free Software Foundation; version 2 of the License.
 *
 *  This program is distributed in the hope that it will be useful,
 *  but WITHOUT ANY WARRANTY; without even the implied warranty of
 *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 *  GNU General Public License for more details.
 *
 *  You should have received a copy of the GNU General Public License
 *  along with this program; if not, write to the Free Software
 *  Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA  02110-1301  USA
 */

#include "config.h"

#include <drizzled/gettext.h>
#include <drizzled/session.h>

#include <stdarg.h>
#include <limits.h>
#include <sys/time.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>

#include "logging.h"
#include "wrap.h"

using namespace drizzled;

/* stolen from mysys/my_getsystime
   until the Session has a good utime "now" we can use
   will have to use this instead */

static uint64_t get_microtime()
{
#if defined(HAVE_GETHRTIME)
  return gethrtime()/1000;
#else
  uint64_t newtime;
  struct timeval t;
  /* loop is because gettimeofday may fail on some systems */
  while (gettimeofday(&t, NULL) != 0) {}
  newtime= (uint64_t)t.tv_sec * 1000000 + t.tv_usec;
  return newtime;
#endif
}

Logging_syslog::Logging_syslog()
  : drizzled::plugin::Logging("Logging_syslog")
{
  syslog_facility= WrapSyslog::getFacilityByName(syslog_module::sysvar_facility);
  if (syslog_facility < 0)
  {
    errmsg_printf(ERRMSG_LVL_WARN,
                  _("syslog facility \"%s\" not known, using \"local0\""),
                  syslog_module::sysvar_facility);
    syslog_facility= WrapSyslog::getFacilityByName("local0");
  }

  syslog_priority= WrapSyslog::getPriorityByName(syslog_module::sysvar_logging_priority);
  if (syslog_priority < 0)
  {
    errmsg_printf(ERRMSG_LVL_WARN,
                  _("syslog priority \"%s\" not known, using \"info\""),
                  syslog_module::sysvar_logging_priority);
    syslog_priority= WrapSyslog::getPriorityByName("info");
  }

  WrapSyslog::singleton().openlog(syslog_module::sysvar_ident);
}


bool Logging_syslog::post (Session *session)
{
  assert(session != NULL);

  if (syslog_module::sysvar_logging_enable == false)
    return false;
  
  // return if query was not too small
  if (session->sent_row_count < syslog_module::sysvar_logging_threshold_big_resultset)
    return false;
  if (session->examined_row_count < syslog_module::sysvar_logging_threshold_big_examined)
    return false;
  
  /* TODO, the session object should have a "utime command completed"
     inside itself, so be more accurate, and so this doesnt have to
     keep calling current_utime, which can be slow */
  
  uint64_t t_mark= get_microtime();

  // return if query was not too slow
  if ((t_mark - session->start_utime) < syslog_module::sysvar_logging_threshold_slow)
    return false;
  
  Session::QueryString query_string(session->getQueryString());

  WrapSyslog::singleton()
    .log(syslog_facility, syslog_priority,
         "thread_id=%ld query_id=%ld"
         " db=\"%.*s\""
         " query=\"%.*s\""
         " command=\"%.*s\""
         " t_connect=%lld t_start=%lld t_lock=%lld"
         " rows_sent=%ld rows_examined=%ld"
         " tmp_table=%ld total_warn_count=%ld\n",
         (unsigned long) session->thread_id,
         (unsigned long) session->getQueryId(),
         (int) session->getSchema().length(),
         session->getSchema().empty() ? "" : session->getSchema().c_str(),
         (int) query_string->length(), 
         query_string->empty() ? "" : query_string->c_str(),
         (int) command_name[session->command].length,
         command_name[session->command].str,
         (unsigned long long) (t_mark - session->getConnectMicroseconds()),
         (unsigned long long) (t_mark - session->start_utime),
         (unsigned long long) (t_mark - session->utime_after_lock),
         (unsigned long) session->sent_row_count,
         (unsigned long) session->examined_row_count,
         (unsigned long) session->tmp_table,
         (unsigned long) session->total_warn_count);
  
    return false;
}