Line data Source code
1 : /*
2 : * This Source Code Form is subject to the terms of the Mozilla Public
3 : * License, v. 2.0. If a copy of the MPL was not distributed with this
4 : * file, You can obtain one at http://mozilla.org/MPL/2.0/.
5 : *
6 : * Copyright 1997 - July 2008 CWI, August 2008 - 2021 MonetDB B.V.
7 : */
8 :
9 : /*
10 : * Martin Kersten
11 : * Language Extensions
12 : * Iterators over scalar ranges are often needed, also at the MAL level.
13 : * The barrier and control primitives are sufficient to mimic them directly.
14 : *
15 : * The modules located in the kernel directory should not
16 : * rely on the MAL datastructures. That's why we have to deal with
17 : * some bat operations here and delegate the signature to the
18 : * proper module upon loading.
19 : *
20 : * Running a script is typically used to initialize a context.
21 : * Therefore we need access to the runtime context.
22 : * For the call variants we have
23 : * to determine an easy way to exchange the parameter/return values.
24 : */
25 :
26 : #include "monetdb_config.h"
27 : #include "querylog.h"
28 : #include "gdk_time.h"
29 : #include "mal_exception.h"
30 :
31 : /* (c) M.L. Kersten
32 : * The query logger facility is hardwired to avoid interference
33 : * with the SQL transaction manager.
34 : *
35 : * The events being captured are stored in separate BATs.
36 : * They are made persistent to accumulate information over
37 : * multiple sessions. This means it has to be explicitly reset
38 : * to avoid disc overflow using querylog.reset().
39 : create table querylog.catalog(
40 : id oid,
41 : "user" string, -- owner of the query
42 : defined timestamp, -- when entered into the cache
43 : query string,
44 : pipe string, -- optimizer pipe-line deployed
45 : optimize bigint -- time in usec
46 : );
47 : create table querylog.calls(
48 : id oid,
49 : "start" timestamp, -- time the statement was started
50 : "stop" timestamp, -- time the statement was completely finished
51 : arguments string,
52 : tuples lng, -- number of tuples in the result set
53 : exec bigint, -- time spent (in usec) until the result export
54 : result bigint, -- time spent (in usec) to ship the result set
55 : cpuload int, -- average cpu load percentage during execution
56 : iowait int -- time waiting for IO to finish in usec
57 : );
58 : */
59 :
60 : static bool QLOGtrace = false;
61 : static bool QLOG_init = false;
62 : static lng QLOGthreshold = 0;
63 :
64 : static BAT *QLOG_cat_id = 0;
65 : static BAT *QLOG_cat_user = 0;
66 : static BAT *QLOG_cat_defined = 0;
67 : static BAT *QLOG_cat_query = 0;
68 : static BAT *QLOG_cat_pipe = 0;
69 : static BAT *QLOG_cat_plan = 0;
70 : static BAT *QLOG_cat_mal = 0;
71 : static BAT *QLOG_cat_optimize = 0;
72 :
73 : static BAT *QLOG_calls_id = 0;
74 : static BAT *QLOG_calls_start = 0;
75 : static BAT *QLOG_calls_stop = 0;
76 : static BAT *QLOG_calls_arguments = 0;
77 : static BAT *QLOG_calls_tuples = 0;
78 : static BAT *QLOG_calls_exec = 0;
79 : static BAT *QLOG_calls_result = 0;
80 : static BAT *QLOG_calls_cpuload = 0;
81 : static BAT *QLOG_calls_iowait = 0;
82 :
83 : static MT_Lock QLOGlock = MT_LOCK_INITIALIZER(QLOGlock);
84 :
85 : static str initQlog(void);
86 :
87 : str
88 100 : QLOGcatalog(BAT **r)
89 : {
90 : int i,cnt = 0;
91 : str msg;
92 :
93 900 : for ( i=0;i < 8; i++)
94 800 : r[i]=0;
95 100 : msg = initQlog();
96 100 : if( msg)
97 : return msg;
98 100 : MT_lock_set(&QLOGlock);
99 100 : r[0] = COLcopy(QLOG_cat_id, QLOG_cat_id->ttype, false, TRANSIENT);
100 100 : r[1] = COLcopy(QLOG_cat_user, QLOG_cat_user->ttype,false, TRANSIENT);
101 100 : r[2] = COLcopy(QLOG_cat_defined, QLOG_cat_defined->ttype,false, TRANSIENT);
102 100 : r[3] = COLcopy(QLOG_cat_query, QLOG_cat_query->ttype,false, TRANSIENT);
103 100 : r[4] = COLcopy(QLOG_cat_pipe, QLOG_cat_pipe->ttype,false, TRANSIENT);
104 100 : r[5] = COLcopy(QLOG_cat_plan, QLOG_cat_plan->ttype,false, TRANSIENT);
105 100 : r[6] = COLcopy(QLOG_cat_mal, QLOG_cat_mal->ttype,false, TRANSIENT);
106 100 : r[7] = COLcopy(QLOG_cat_optimize, QLOG_cat_optimize->ttype,false, TRANSIENT);
107 100 : MT_lock_unset(&QLOGlock);
108 900 : for ( i = 0; i< 8; i++)
109 800 : cnt += r[i] != 0;
110 100 : if( cnt != 8){
111 0 : for ( i = 0; i< 8; i++)
112 0 : if( r[i]){
113 0 : BBPunfix(r[i]->batCacheid);
114 0 : r[i]=0;
115 : }
116 : }
117 100 : if( r[0])
118 : return MAL_SUCCEED;
119 0 : throw(MAL,"catalog_queries", SQLSTATE(HY013) MAL_MALLOC_FAIL);
120 : }
121 :
122 : str
123 75 : QLOGcalls(BAT **r)
124 : {
125 : int i, cnt = 0;
126 : str msg;
127 :
128 825 : for ( i=0;i < 10; i++)
129 750 : r[i]=0;
130 75 : msg = initQlog();
131 75 : if( msg)
132 : return msg;
133 75 : MT_lock_set(&QLOGlock);
134 75 : r[0] = COLcopy(QLOG_calls_id, QLOG_calls_id->ttype, false, TRANSIENT);
135 75 : r[1] = COLcopy(QLOG_calls_start, QLOG_calls_start->ttype,false, TRANSIENT);
136 75 : r[2] = COLcopy(QLOG_calls_stop, QLOG_calls_stop->ttype,false, TRANSIENT);
137 75 : r[3] = COLcopy(QLOG_calls_arguments, QLOG_calls_arguments->ttype,false, TRANSIENT);
138 75 : r[4] = COLcopy(QLOG_calls_tuples, QLOG_calls_tuples->ttype,false, TRANSIENT);
139 75 : r[5] = COLcopy(QLOG_calls_exec, QLOG_calls_exec->ttype,false, TRANSIENT);
140 75 : r[6] = COLcopy(QLOG_calls_result, QLOG_calls_result->ttype,false, TRANSIENT);
141 75 : r[7] = COLcopy(QLOG_calls_cpuload, QLOG_calls_cpuload->ttype,false, TRANSIENT);
142 75 : r[8] = COLcopy(QLOG_calls_iowait, QLOG_calls_iowait->ttype,false, TRANSIENT);
143 75 : MT_lock_unset(&QLOGlock);
144 750 : for ( i = 0; i< 9; i++)
145 675 : cnt += r[i] != 0;
146 75 : if( cnt != 9){
147 0 : for ( i = 0; i< 9; i++)
148 0 : if( r[i]){
149 0 : BBPunfix(r[i]->batCacheid);
150 0 : r[i]=0;
151 : }
152 : }
153 75 : if( r[0])
154 : return MAL_SUCCEED;
155 0 : throw(MAL,"catalog_calls", SQLSTATE(HY013) MAL_MALLOC_FAIL);
156 : }
157 :
158 : #define MAXCOMMITLIST 32
159 : static bat commitlist[MAXCOMMITLIST];
160 : static int committop=1;
161 :
162 : static BAT *
163 204 : QLOGcreate(str hnme, str tnme, int tt)
164 : {
165 : BAT *b;
166 : char buf[128];
167 :
168 204 : snprintf(buf, 128, "querylog_%s_%s", hnme, tnme);
169 204 : b = BATdescriptor(BBPindex(buf));
170 204 : if (b) {
171 : /* make append-only in case this wasn't done when created */
172 0 : return BATsetaccess(b, BAT_APPEND);
173 : }
174 :
175 204 : b = COLnew(0, tt, 1 << 16, PERSISTENT);
176 204 : if (b == NULL)
177 : return NULL;
178 204 : if ((b = BATsetaccess(b, BAT_APPEND)) == NULL)
179 : return NULL;
180 :
181 408 : if (BBPrename(b->batCacheid, buf) != 0 ||
182 204 : BATmode(b, false) != GDK_SUCCEED) {
183 0 : BBPunfix(b->batCacheid);
184 0 : return NULL;
185 : }
186 204 : commitlist[committop++]= b->batCacheid;
187 204 : assert(committop < MAXCOMMITLIST);
188 : return b;
189 : }
190 :
191 : #define cleanup(X) if (X) { (X)->batTransient = true; BBPrename((X)->batCacheid,"_"); BBPunfix((X)->batCacheid); } (X) = NULL;
192 :
193 : static void
194 0 : _QLOGcleanup(void)
195 : {
196 0 : cleanup(QLOG_cat_id);
197 0 : cleanup(QLOG_cat_user);
198 0 : cleanup(QLOG_cat_defined);
199 0 : cleanup(QLOG_cat_query);
200 0 : cleanup(QLOG_cat_pipe);
201 0 : cleanup(QLOG_cat_plan);
202 0 : cleanup(QLOG_cat_mal);
203 0 : cleanup(QLOG_cat_optimize);
204 :
205 0 : cleanup(QLOG_calls_id);
206 0 : cleanup(QLOG_calls_start);
207 0 : cleanup(QLOG_calls_stop);
208 0 : cleanup(QLOG_calls_arguments);
209 0 : cleanup(QLOG_calls_tuples);
210 0 : cleanup(QLOG_calls_exec);
211 0 : cleanup(QLOG_calls_result);
212 0 : cleanup(QLOG_calls_cpuload);
213 0 : cleanup(QLOG_calls_iowait);
214 0 : }
215 :
216 : static str
217 12 : _initQlog(void)
218 : {
219 12 : QLOG_cat_id = QLOGcreate("cat","id",TYPE_oid);
220 12 : QLOG_cat_user = QLOGcreate("cat","user",TYPE_str);
221 12 : QLOG_cat_defined = QLOGcreate("cat","defined",TYPE_timestamp);
222 12 : QLOG_cat_query = QLOGcreate("cat","query",TYPE_str);
223 12 : QLOG_cat_pipe = QLOGcreate("cat","pipe",TYPE_str);
224 12 : QLOG_cat_plan = QLOGcreate("cat","size",TYPE_str);
225 12 : QLOG_cat_mal = QLOGcreate("cat","mal",TYPE_int);
226 12 : QLOG_cat_optimize = QLOGcreate("cat","optimize",TYPE_lng);
227 :
228 12 : QLOG_calls_id = QLOGcreate("calls","id",TYPE_oid);
229 12 : QLOG_calls_start = QLOGcreate("calls","start",TYPE_timestamp);
230 12 : QLOG_calls_stop = QLOGcreate("calls","stop",TYPE_timestamp);
231 12 : QLOG_calls_arguments = QLOGcreate("calls","arguments",TYPE_str);
232 12 : QLOG_calls_tuples = QLOGcreate("calls","tuples",TYPE_lng);
233 12 : QLOG_calls_exec = QLOGcreate("calls","exec",TYPE_lng);
234 12 : QLOG_calls_result = QLOGcreate("calls","result",TYPE_lng);
235 12 : QLOG_calls_cpuload = QLOGcreate("calls","cpuload",TYPE_int);
236 12 : QLOG_calls_iowait = QLOGcreate("calls","iowait",TYPE_int);
237 :
238 12 : if( QLOG_cat_id == NULL || QLOG_cat_user == NULL || QLOG_cat_defined == NULL ||
239 12 : QLOG_cat_query == NULL || QLOG_cat_pipe == NULL || QLOG_cat_plan == NULL ||
240 12 : QLOG_cat_mal == NULL || QLOG_cat_optimize == NULL || QLOG_calls_id == NULL ||
241 12 : QLOG_calls_start == NULL || QLOG_calls_stop == NULL || QLOG_calls_arguments == NULL ||
242 12 : QLOG_calls_tuples == NULL || QLOG_calls_exec == NULL || QLOG_calls_result == NULL ||
243 12 : QLOG_calls_cpuload == NULL || QLOG_calls_iowait == NULL){
244 0 : _QLOGcleanup();
245 0 : throw(MAL,"querylog.init", SQLSTATE(HY013) MAL_MALLOC_FAIL);
246 : }
247 :
248 12 : QLOG_init = true;
249 12 : TMsubcommit_list(commitlist, NULL, committop, getBBPlogno(), getBBPtransid());
250 12 : return MAL_SUCCEED;
251 : }
252 :
253 : static str
254 186 : initQlog(void)
255 : {
256 : str msg;
257 :
258 186 : if (QLOG_init)
259 : return MAL_SUCCEED; /* already initialized */
260 12 : MT_lock_set(&QLOGlock);
261 12 : msg = _initQlog();
262 12 : MT_lock_unset(&QLOGlock);
263 12 : return msg;
264 : }
265 :
266 : str
267 1 : QLOGenable(void *ret)
268 : {
269 : (void) ret;
270 1 : QLOGtrace = true;
271 1 : QLOGthreshold = 0;
272 1 : return MAL_SUCCEED;
273 : }
274 :
275 : str
276 0 : QLOGenableThreshold(void *ret, int *threshold)
277 : {
278 : (void) ret;
279 0 : QLOGtrace = true;
280 0 : QLOGthreshold = *threshold * LL_CONSTANT(1000);
281 0 : return MAL_SUCCEED;
282 : }
283 :
284 : str
285 1 : QLOGdisable(void *ret)
286 : {
287 : (void) ret;
288 1 : QLOGtrace = false;
289 1 : return MAL_SUCCEED;
290 : }
291 :
292 : int
293 347831 : QLOGisset(void)
294 : {
295 347831 : return QLOGtrace;
296 : }
297 :
298 : static str
299 0 : QLOGissetFcn(int *ret)
300 : {
301 0 : *ret = QLOGtrace;
302 0 : return MAL_SUCCEED;
303 : }
304 :
305 : str
306 1 : QLOGempty(void *ret)
307 : {
308 : str msg;
309 :
310 : (void) ret;
311 1 : msg = initQlog();
312 1 : if( msg)
313 : return msg;
314 1 : MT_lock_set(&QLOGlock);
315 : /* drop all querylog tables */
316 :
317 1 : BATclear(QLOG_cat_id,true);
318 1 : BATclear(QLOG_cat_user,true);
319 1 : BATclear(QLOG_cat_defined,true);
320 1 : BATclear(QLOG_cat_query,true);
321 1 : BATclear(QLOG_cat_pipe,true);
322 1 : BATclear(QLOG_cat_plan,true);
323 1 : BATclear(QLOG_cat_mal,true);
324 1 : BATclear(QLOG_cat_optimize,true);
325 :
326 1 : BATclear(QLOG_calls_id,true);
327 1 : BATclear(QLOG_calls_start,true);
328 1 : BATclear(QLOG_calls_stop,true);
329 1 : BATclear(QLOG_calls_arguments,true);
330 1 : BATclear(QLOG_calls_tuples,true);
331 1 : BATclear(QLOG_calls_exec,true);
332 1 : BATclear(QLOG_calls_result,true);
333 1 : BATclear(QLOG_calls_cpuload,true);
334 1 : BATclear(QLOG_calls_iowait,true);
335 :
336 1 : TMsubcommit_list(commitlist, NULL, committop, getBBPlogno(), getBBPtransid());
337 1 : MT_lock_unset(&QLOGlock);
338 1 : return MAL_SUCCEED;
339 : }
340 :
341 : static str
342 5 : QLOGappend(Client cntxt, MalBlkPtr mb, MalStkPtr stk, InstrPtr pci)
343 : {
344 5 : oid *ret = getArgReference_oid(stk,pci,0);
345 5 : str *q = getArgReference_str(stk,pci,1);
346 5 : str *pipe = getArgReference_str(stk,pci,2);
347 5 : str *usr = getArgReference_str(stk,pci,3);
348 5 : timestamp *tick = getArgReference_TYPE(stk,pci,4,timestamp);
349 : oid o;
350 5 : InstrPtr sig = getInstrPtr(mb,0);
351 : char buf[128], *nme= buf;
352 : str msg;
353 :
354 : (void) cntxt;
355 5 : msg = initQlog();
356 5 : if( msg)
357 : return msg;
358 5 : snprintf(buf,128,"%s.%s", getModuleId(sig), getFunctionId(sig));
359 5 : MT_lock_set(&QLOGlock);
360 5 : o = BUNfnd(QLOG_cat_id, &mb->tag);
361 5 : if ( o == BUN_NONE){
362 5 : *ret = mb->tag;
363 10 : if (BUNappend(QLOG_cat_id,&mb->tag,false) != GDK_SUCCEED ||
364 10 : BUNappend(QLOG_cat_query,*q,false) != GDK_SUCCEED ||
365 10 : BUNappend(QLOG_cat_pipe,*pipe,false) != GDK_SUCCEED ||
366 10 : BUNappend(QLOG_cat_plan,nme,false) != GDK_SUCCEED ||
367 10 : BUNappend(QLOG_cat_mal,&mb->stop,false) != GDK_SUCCEED ||
368 10 : BUNappend(QLOG_cat_optimize,&mb->optimize,false) != GDK_SUCCEED ||
369 10 : BUNappend(QLOG_cat_user,*usr,false) != GDK_SUCCEED ||
370 5 : BUNappend(QLOG_cat_defined,tick,false) != GDK_SUCCEED) {
371 0 : MT_lock_unset(&QLOGlock);
372 0 : throw(MAL, "querylog.append", SQLSTATE(HY013) MAL_MALLOC_FAIL);
373 : }
374 : }
375 5 : TMsubcommit_list(commitlist, NULL, committop, getBBPlogno(), getBBPtransid());
376 5 : MT_lock_unset(&QLOGlock);
377 5 : return MAL_SUCCEED;
378 : }
379 :
380 : static str
381 112585 : QLOGdefineNaive(void *ret, str *qry, str *opt, int *nr)
382 : {
383 : // Nothing else to be done.
384 : (void) ret;
385 : (void) qry;
386 : (void) opt;
387 : (void) nr;
388 112585 : return MAL_SUCCEED;
389 : }
390 :
391 : static str
392 0 : QLOGcontextNaive(void *ret, str *release, str *version, str *revision, str *uri)
393 : {
394 : // Nothing else to be done.
395 : (void) ret;
396 : (void) release;
397 : (void) version;
398 : (void) revision;
399 : (void) uri;
400 0 : return MAL_SUCCEED;
401 : }
402 :
403 : static str
404 5 : QLOGcall(Client cntxt, MalBlkPtr mb, MalStkPtr stk, InstrPtr pci)
405 : {
406 5 : timestamp *tick1 = getArgReference_TYPE(stk,pci,1,timestamp);
407 5 : timestamp *tick2 = getArgReference_TYPE(stk,pci,2,timestamp);
408 5 : str *arg = getArgReference_str(stk,pci,3);
409 5 : lng *tuples = getArgReference_lng(stk,pci,4);
410 5 : lng *xtime = getArgReference_lng(stk,pci,5);
411 5 : lng *rtime = getArgReference_lng(stk,pci,6);
412 5 : int *cpu = getArgReference_int(stk,pci,7);
413 5 : int *iowait = getArgReference_int(stk,pci,8);
414 : str msg;
415 :
416 : (void) cntxt;
417 :
418 5 : msg = initQlog();
419 5 : if( msg)
420 : return msg;
421 5 : if ( *xtime + *rtime < QLOGthreshold)
422 : return MAL_SUCCEED;
423 5 : MT_lock_set(&QLOGlock);
424 10 : if (BUNappend(QLOG_calls_id,&mb->tag,false) != GDK_SUCCEED ||
425 10 : BUNappend(QLOG_calls_start,tick1,false) != GDK_SUCCEED ||
426 10 : BUNappend(QLOG_calls_stop,tick2,false) != GDK_SUCCEED ||
427 10 : BUNappend(QLOG_calls_arguments,*arg,false) != GDK_SUCCEED ||
428 10 : BUNappend(QLOG_calls_tuples,tuples,false) != GDK_SUCCEED ||
429 10 : BUNappend(QLOG_calls_exec,xtime,false) != GDK_SUCCEED ||
430 10 : BUNappend(QLOG_calls_result,rtime,false) != GDK_SUCCEED ||
431 10 : BUNappend(QLOG_calls_cpuload,cpu,false) != GDK_SUCCEED ||
432 5 : BUNappend(QLOG_calls_iowait,iowait,false) != GDK_SUCCEED) {
433 0 : MT_lock_unset(&QLOGlock);
434 0 : throw(MAL, "querylog.call", SQLSTATE(HY013) MAL_MALLOC_FAIL);
435 : }
436 5 : TMsubcommit_list(commitlist, NULL, committop, getBBPlogno(), getBBPtransid());
437 5 : MT_lock_unset(&QLOGlock);
438 5 : return MAL_SUCCEED;
439 : }
440 :
441 : #include "mel.h"
442 : mel_func querylog_init_funcs[] = {
443 : command("querylog", "enable", QLOGenableThreshold, false, "Turn on the query logger", args(0,1, arg("threshold",int))),
444 : command("querylog", "enable", QLOGenable, false, "Turn on the query logger", noargs),
445 : command("querylog", "disable", QLOGdisable, false, "Turn off the query logger", noargs),
446 : command("querylog", "isset", QLOGissetFcn, false, "Return status of query logger", args(1,1, arg("",int))),
447 : command("querylog", "empty", QLOGempty, false, "Clear the query log tables", noargs),
448 : pattern("querylog", "append", QLOGappend, false, "Add a new query call to the query log", args(0,4, arg("q",str),arg("pipe",str),arg("usr",str),arg("tick",timestamp))),
449 : command("querylog", "define", QLOGdefineNaive, false, "Noop operation, just marking the query", args(0,3, arg("q",str),arg("pipe",str),arg("size",int))),
450 : command("querylog", "context", QLOGcontextNaive, false, "Noop operation, just marking the query", args(0,4, arg("release",str),arg("version",str),arg("revision",str),arg("uri",str))),
451 : pattern("querylog", "call", QLOGcall, false, "Add a new query call to the query log", args(0,8, arg("tick1",timestamp),arg("tick2",timestamp),arg("arg",str),arg("tuples",lng),arg("xtime",lng),arg("rtime",lng),arg("cpu",int),arg("iowait",int))),
452 : { .imp=NULL }
453 : };
454 : #include "mal_import.h"
455 : #ifdef _MSC_VER
456 : #undef read
457 : #pragma section(".CRT$XCU",read)
458 : #endif
459 257 : LIB_STARTUP_FUNC(init_querylog_mal)
460 257 : { mal_module("querylog", NULL, querylog_init_funcs); }
|
