1 // Copyright (c) 1999-2018 David Muse
2 // See the file COPYING for more information
3
4 #include <sqlrelay/sqlrserver.h>
5 #include <rudiments/process.h>
6 #include <rudiments/charstring.h>
7 #include <rudiments/file.h>
8 #include <rudiments/permissions.h>
9 #include <rudiments/filesystem.h>
10 #include <rudiments/stringbuffer.h>
11
12 class SQLRSERVER_DLLSPEC sqlrlogger_slowqueries : public sqlrlogger {
13 public:
14 sqlrlogger_slowqueries(sqlrloggers *ls,
15 domnode *parameters);
16 ~sqlrlogger_slowqueries();
17
18 bool init(sqlrlistener *sqlrl,
19 sqlrserverconnection *sqlrcon);
20 bool run(sqlrlistener *sqlrl,
21 sqlrserverconnection *sqlrcon,
22 sqlrservercursor *sqlrcur,
23 sqlrlogger_loglevel_t level,
24 sqlrevent_t event,
25 const char *info);
26 private:
27 char *querylogname;
28 file querylog;
29 uint64_t sec;
30 uint64_t usec;
31 uint64_t totalusec;
32 bool usecommand;
33 bool enabled;
34 };
35
sqlrlogger_slowqueries(sqlrloggers * ls,domnode * parameters)36 sqlrlogger_slowqueries::sqlrlogger_slowqueries(sqlrloggers *ls,
37 domnode *parameters) :
38 sqlrlogger(ls,parameters) {
39 querylogname=NULL;
40 sec=charstring::toInteger(parameters->getAttributeValue("sec"));
41 usec=charstring::toInteger(parameters->getAttributeValue("usec"));
42 totalusec=sec*1000000+usec;
43 usecommand=!charstring::compareIgnoringCase(
44 parameters->getAttributeValue("timer"),"command");
45 enabled=!charstring::isNo(parameters->getAttributeValue("enabled"));
46 }
47
~sqlrlogger_slowqueries()48 sqlrlogger_slowqueries::~sqlrlogger_slowqueries() {
49 querylog.flushWriteBuffer(-1,-1);
50 delete[] querylogname;
51 }
52
init(sqlrlistener * sqlrl,sqlrserverconnection * sqlrcon)53 bool sqlrlogger_slowqueries::init(sqlrlistener *sqlrl,
54 sqlrserverconnection *sqlrcon) {
55
56 if (!enabled) {
57 return true;
58 }
59
60 // don't log anything for the listener
61 if (!sqlrcon) {
62 return true;
63 }
64
65 // get the pid
66 pid_t pid=process::getProcessId();
67
68 // build up the query log name
69 delete[] querylogname;
70 charstring::printf(&querylogname,
71 "%s/sqlr-connection-%s-querylog.%ld",
72 sqlrcon->cont->getLogDir(),
73 sqlrcon->cont->getId(),(long)pid);
74
75 // remove any old log file
76 file::remove(querylogname);
77
78 // create the new log file
79 if (!querylog.create(querylogname,
80 permissions::evalPermString("rw-------"))) {
81 return false;
82 }
83
84 // optimize
85 filesystem fs;
86 fs.open(querylogname);
87 querylog.setWriteBufferSize(fs.getOptimumTransferBlockSize());
88 return true;
89 }
90
91 static const char *days[]={"Sun","Mon","Tue","Wed","Thu","Fri","Sat"};
92
run(sqlrlistener * sqlrl,sqlrserverconnection * sqlrcon,sqlrservercursor * sqlrcur,sqlrlogger_loglevel_t level,sqlrevent_t event,const char * info)93 bool sqlrlogger_slowqueries::run(sqlrlistener *sqlrl,
94 sqlrserverconnection *sqlrcon,
95 sqlrservercursor *sqlrcur,
96 sqlrlogger_loglevel_t level,
97 sqlrevent_t event,
98 const char *info) {
99
100 if (!enabled) {
101 return true;
102 }
103
104 // don't log anything for the listener
105 if (!sqlrcon) {
106 return true;
107 }
108
109 // don't do anything unless we got INFO/QUERY
110 if (level!=SQLRLOGGER_LOGLEVEL_INFO || event!=SQLREVENT_QUERY) {
111 return true;
112 }
113
114 // reinit the log if the file was switched
115 file querylog2;
116 if (querylog2.open(querylogname,O_RDONLY)) {
117 ino_t inode1=querylog.getInode();
118 ino_t inode2=querylog2.getInode();
119 querylog2.close();
120 if (inode1!=inode2) {
121 querylog.flushWriteBuffer(-1,-1);
122 querylog.close();
123 init(sqlrl,sqlrcon);
124 }
125 }
126
127 // calculate times
128 uint64_t startsec=(usecommand)?sqlrcur->getCommandStartSec():
129 sqlrcur->getQueryStartSec();
130 uint64_t startusec=(usecommand)?sqlrcur->getCommandStartUSec():
131 sqlrcur->getQueryStartUSec();
132 uint64_t endsec=(usecommand)?sqlrcur->getCommandEndSec():
133 sqlrcur->getQueryEndSec();
134 uint64_t endusec=(usecommand)?sqlrcur->getCommandEndUSec():
135 sqlrcur->getQueryEndUSec();
136
137 uint64_t queryusec=((endsec-startsec)*1000000)+
138 endusec-startusec;
139 double querysec=((double)queryusec)/1000000.0;
140
141 // log times
142 if (queryusec>=totalusec) {
143
144 datetime dt;
145 dt.getSystemDateAndTime();
146 char datebuffer[26];
147 charstring::printf(datebuffer,sizeof(datebuffer),
148 "%s %d %s % 2d %02d:%02d:%02d",
149 days[dt.getDayOfWeek()-1],
150 dt.getYear(),
151 dt.getMonthAbbreviation(),
152 dt.getDayOfMonth(),
153 dt.getHour(),
154 dt.getMinutes(),
155 dt.getSeconds());
156
157 stringbuffer logentry;
158 logentry.append(datebuffer)->append(" :\n");
159 logentry.append(sqlrcur->getQueryBuffer());
160 logentry.append("\n");
161 logentry.append("execution time: ")->append(querysec,6);
162 logentry.append("\n");
163 if ((size_t)querylog.write(logentry.getString(),
164 logentry.getStringLength())!=
165 logentry.getStringLength()) {
166 return false;
167 }
168 //querylog.flushWriteBuffer(-1,-1);
169 }
170 return true;
171 }
172
173 extern "C" {
new_sqlrlogger_slowqueries(sqlrloggers * ls,domnode * parameters)174 SQLRSERVER_DLLSPEC sqlrlogger *new_sqlrlogger_slowqueries(
175 sqlrloggers *ls,
176 domnode *parameters) {
177 return new sqlrlogger_slowqueries(ls,parameters);
178 }
179 }
180