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 - 2019 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 "mtime.h" |
29 | |
30 | /* (c) M.L. Kersten |
31 | * The query logger facility is hardwired to avoid interference |
32 | * with the SQL transaction manager. |
33 | * |
34 | * The events being captured are stored in separate BATs. |
35 | * They are made persistent to accumulate information over |
36 | * multiple sessions. This means it has to be explicitly reset |
37 | * to avoid disc overflow using querylog.reset(). |
38 | create table querylog.catalog( |
39 | id oid, |
40 | "user" string, -- owner of the query |
41 | defined timestamp, -- when entered into the cache |
42 | query string, |
43 | pipe string, -- optimizer pipe-line deployed |
44 | optimize bigint -- time in usec |
45 | ); |
46 | create table querylog.calls( |
47 | id oid, |
48 | "start" timestamp, -- time the statement was started |
49 | "stop" timestamp, -- time the statement was completely finished |
50 | arguments string, |
51 | tuples lng, -- number of tuples in the result set |
52 | exec bigint, -- time spent (in usec) until the result export |
53 | result bigint, -- time spent (in usec) to ship the result set |
54 | cpuload int, -- average cpu load percentage during execution |
55 | iowait int -- time waiting for IO to finish in usec |
56 | ); |
57 | */ |
58 | |
59 | static bool QLOGtrace = false; |
60 | static bool QLOG_init = false; |
61 | static int QLOGthreshold = 0; |
62 | |
63 | static BAT *QLOG_cat_id = 0; |
64 | static BAT *QLOG_cat_user = 0; |
65 | static BAT *QLOG_cat_defined = 0; |
66 | static BAT *QLOG_cat_query = 0; |
67 | static BAT *QLOG_cat_pipe = 0; |
68 | static BAT *QLOG_cat_plan = 0; |
69 | static BAT *QLOG_cat_mal = 0; |
70 | static BAT *QLOG_cat_optimize = 0; |
71 | |
72 | static BAT *QLOG_calls_id = 0; |
73 | static BAT *QLOG_calls_start = 0; |
74 | static BAT *QLOG_calls_stop = 0; |
75 | static BAT *QLOG_calls_arguments = 0; |
76 | static BAT *QLOG_calls_tuples = 0; |
77 | static BAT *QLOG_calls_exec = 0; |
78 | static BAT *QLOG_calls_result = 0; |
79 | static BAT *QLOG_calls_cpuload = 0; |
80 | static BAT *QLOG_calls_iowait = 0; |
81 | |
82 | str |
83 | QLOGcatalog(BAT **r) |
84 | { |
85 | int i,cnt = 0; |
86 | str msg; |
87 | |
88 | for ( i=0;i < 8; i++) |
89 | r[i]=0; |
90 | msg = initQlog(); |
91 | if( msg) |
92 | return msg; |
93 | MT_lock_set(&mal_profileLock); |
94 | r[0] = COLcopy(QLOG_cat_id, QLOG_cat_id->ttype, false, TRANSIENT); |
95 | r[1] = COLcopy(QLOG_cat_user, QLOG_cat_user->ttype,false, TRANSIENT); |
96 | r[2] = COLcopy(QLOG_cat_defined, QLOG_cat_defined->ttype,false, TRANSIENT); |
97 | r[3] = COLcopy(QLOG_cat_query, QLOG_cat_query->ttype,false, TRANSIENT); |
98 | r[4] = COLcopy(QLOG_cat_pipe, QLOG_cat_pipe->ttype,false, TRANSIENT); |
99 | r[5] = COLcopy(QLOG_cat_plan, QLOG_cat_plan->ttype,false, TRANSIENT); |
100 | r[6] = COLcopy(QLOG_cat_mal, QLOG_cat_mal->ttype,false, TRANSIENT); |
101 | r[7] = COLcopy(QLOG_cat_optimize, QLOG_cat_optimize->ttype,false, TRANSIENT); |
102 | MT_lock_unset(&mal_profileLock); |
103 | for ( i = 0; i< 8; i++) |
104 | cnt += r[i] != 0; |
105 | if( cnt != 8){ |
106 | for ( i = 0; i< 8; i++) |
107 | if( r[i]){ |
108 | BBPunfix(r[i]->batCacheid); |
109 | r[i]=0; |
110 | } |
111 | } |
112 | if( r[0]) |
113 | return MAL_SUCCEED; |
114 | throw(MAL,"catalog_queries" , SQLSTATE(HY001) MAL_MALLOC_FAIL); |
115 | } |
116 | |
117 | str |
118 | QLOGcalls(BAT **r) |
119 | { |
120 | int i, cnt = 0; |
121 | str msg; |
122 | |
123 | for ( i=0;i < 10; i++) |
124 | r[i]=0; |
125 | msg = initQlog(); |
126 | if( msg) |
127 | return msg; |
128 | MT_lock_set(&mal_profileLock); |
129 | r[0] = COLcopy(QLOG_calls_id, QLOG_calls_id->ttype, false, TRANSIENT); |
130 | r[1] = COLcopy(QLOG_calls_start, QLOG_calls_start->ttype,false, TRANSIENT); |
131 | r[2] = COLcopy(QLOG_calls_stop, QLOG_calls_stop->ttype,false, TRANSIENT); |
132 | r[3] = COLcopy(QLOG_calls_arguments, QLOG_calls_arguments->ttype,false, TRANSIENT); |
133 | r[4] = COLcopy(QLOG_calls_tuples, QLOG_calls_tuples->ttype,false, TRANSIENT); |
134 | r[5] = COLcopy(QLOG_calls_exec, QLOG_calls_exec->ttype,false, TRANSIENT); |
135 | r[6] = COLcopy(QLOG_calls_result, QLOG_calls_result->ttype,false, TRANSIENT); |
136 | r[7] = COLcopy(QLOG_calls_cpuload, QLOG_calls_cpuload->ttype,false, TRANSIENT); |
137 | r[8] = COLcopy(QLOG_calls_iowait, QLOG_calls_iowait->ttype,false, TRANSIENT); |
138 | MT_lock_unset(&mal_profileLock); |
139 | for ( i = 0; i< 9; i++) |
140 | cnt += r[i] != 0; |
141 | if( cnt != 9){ |
142 | for ( i = 0; i< 9; i++) |
143 | if( r[i]){ |
144 | BBPunfix(r[i]->batCacheid); |
145 | r[i]=0; |
146 | } |
147 | } |
148 | if( r[0]) |
149 | return MAL_SUCCEED; |
150 | throw(MAL,"catalog_calls" , SQLSTATE(HY001) MAL_MALLOC_FAIL); |
151 | } |
152 | |
153 | #define MAXCOMMITLIST 32 |
154 | static bat commitlist[MAXCOMMITLIST]; |
155 | static int committop=1; |
156 | |
157 | static BAT * |
158 | QLOGcreate(str hnme, str tnme, int tt) |
159 | { |
160 | BAT *b; |
161 | char buf[128]; |
162 | |
163 | snprintf(buf, 128, "querylog_%s_%s" , hnme, tnme); |
164 | b = BATdescriptor(BBPindex(buf)); |
165 | if (b) |
166 | return b; |
167 | |
168 | b = COLnew(0, tt, 1 << 16, PERSISTENT); |
169 | if (b == NULL) |
170 | return NULL; |
171 | |
172 | if (BBPrename(b->batCacheid, buf) != 0 || |
173 | BATmode(b, false) != GDK_SUCCEED) { |
174 | BBPunfix(b->batCacheid); |
175 | return NULL; |
176 | } |
177 | commitlist[committop++]= b->batCacheid; |
178 | assert(committop < MAXCOMMITLIST); |
179 | return b; |
180 | } |
181 | |
182 | #define cleanup(X) if (X) { (X)->batTransient = true; BBPrename((X)->batCacheid,"_"); BBPunfix((X)->batCacheid); } (X) = NULL; |
183 | |
184 | static void |
185 | _QLOGcleanup(void) |
186 | { |
187 | cleanup(QLOG_cat_id); |
188 | cleanup(QLOG_cat_user); |
189 | cleanup(QLOG_cat_defined); |
190 | cleanup(QLOG_cat_query); |
191 | cleanup(QLOG_cat_pipe); |
192 | cleanup(QLOG_cat_plan); |
193 | cleanup(QLOG_cat_mal); |
194 | cleanup(QLOG_cat_optimize); |
195 | |
196 | cleanup(QLOG_calls_id); |
197 | cleanup(QLOG_calls_start); |
198 | cleanup(QLOG_calls_stop); |
199 | cleanup(QLOG_calls_arguments); |
200 | cleanup(QLOG_calls_tuples); |
201 | cleanup(QLOG_calls_exec); |
202 | cleanup(QLOG_calls_result); |
203 | cleanup(QLOG_calls_cpuload); |
204 | cleanup(QLOG_calls_iowait); |
205 | } |
206 | |
207 | static str |
208 | _initQlog(void) |
209 | { |
210 | QLOG_cat_id = QLOGcreate("cat" ,"id" ,TYPE_oid); |
211 | QLOG_cat_user = QLOGcreate("cat" ,"user" ,TYPE_str); |
212 | QLOG_cat_defined = QLOGcreate("cat" ,"defined" ,TYPE_timestamp); |
213 | QLOG_cat_query = QLOGcreate("cat" ,"query" ,TYPE_str); |
214 | QLOG_cat_pipe = QLOGcreate("cat" ,"pipe" ,TYPE_str); |
215 | QLOG_cat_plan = QLOGcreate("cat" ,"size" ,TYPE_str); |
216 | QLOG_cat_mal = QLOGcreate("cat" ,"mal" ,TYPE_int); |
217 | QLOG_cat_optimize = QLOGcreate("cat" ,"optimize" ,TYPE_lng); |
218 | |
219 | QLOG_calls_id = QLOGcreate("calls" ,"id" ,TYPE_oid); |
220 | QLOG_calls_start = QLOGcreate("calls" ,"start" ,TYPE_timestamp); |
221 | QLOG_calls_stop = QLOGcreate("calls" ,"stop" ,TYPE_timestamp); |
222 | QLOG_calls_arguments = QLOGcreate("calls" ,"arguments" ,TYPE_str); |
223 | QLOG_calls_tuples = QLOGcreate("calls" ,"tuples" ,TYPE_lng); |
224 | QLOG_calls_exec = QLOGcreate("calls" ,"exec" ,TYPE_lng); |
225 | QLOG_calls_result = QLOGcreate("calls" ,"result" ,TYPE_lng); |
226 | QLOG_calls_cpuload = QLOGcreate("calls" ,"cpuload" ,TYPE_int); |
227 | QLOG_calls_iowait = QLOGcreate("calls" ,"iowait" ,TYPE_int); |
228 | |
229 | if( QLOG_cat_id == NULL || QLOG_cat_user == NULL || QLOG_cat_defined == NULL || |
230 | QLOG_cat_query == NULL || QLOG_cat_pipe == NULL || QLOG_cat_plan == NULL || |
231 | QLOG_cat_mal == NULL || QLOG_cat_optimize == NULL || QLOG_calls_id == NULL || |
232 | QLOG_calls_start == NULL || QLOG_calls_stop == NULL || QLOG_calls_arguments == NULL || |
233 | QLOG_calls_tuples == NULL || QLOG_calls_exec == NULL || QLOG_calls_result == NULL || |
234 | QLOG_calls_cpuload == NULL || QLOG_calls_iowait == NULL){ |
235 | _QLOGcleanup(); |
236 | throw(MAL,"querylog.init" , SQLSTATE(HY001) MAL_MALLOC_FAIL); |
237 | } |
238 | |
239 | QLOG_init = true; |
240 | TMsubcommit_list(commitlist, committop); |
241 | return MAL_SUCCEED; |
242 | } |
243 | |
244 | str |
245 | initQlog(void) |
246 | { |
247 | str msg; |
248 | |
249 | if (QLOG_init) |
250 | return MAL_SUCCEED; /* already initialized */ |
251 | MT_lock_set(&mal_profileLock); |
252 | msg = _initQlog(); |
253 | MT_lock_unset(&mal_profileLock); |
254 | return msg; |
255 | } |
256 | |
257 | str |
258 | QLOGenable(void *ret) |
259 | { |
260 | (void) ret; |
261 | QLOGtrace = true; |
262 | return MAL_SUCCEED; |
263 | } |
264 | |
265 | str |
266 | QLOGenableThreshold(void *ret, int *threshold) |
267 | { |
268 | (void) ret; |
269 | QLOGthreshold = *threshold; |
270 | return MAL_SUCCEED; |
271 | } |
272 | |
273 | str |
274 | QLOGdisable(void *ret) |
275 | { |
276 | (void) ret; |
277 | QLOGtrace = false; |
278 | return MAL_SUCCEED; |
279 | } |
280 | |
281 | int |
282 | QLOGisset(void) |
283 | { |
284 | return QLOGtrace; |
285 | } |
286 | |
287 | str |
288 | QLOGissetFcn(int *ret) |
289 | { |
290 | *ret = QLOGtrace; |
291 | return MAL_SUCCEED; |
292 | } |
293 | |
294 | str |
295 | QLOGempty(void *ret) |
296 | { |
297 | str msg; |
298 | |
299 | (void) ret; |
300 | msg = initQlog(); |
301 | if( msg) |
302 | return msg; |
303 | MT_lock_set(&mal_profileLock); |
304 | /* drop all querylog tables */ |
305 | |
306 | BATclear(QLOG_cat_id,true); |
307 | BATclear(QLOG_cat_user,true); |
308 | BATclear(QLOG_cat_defined,true); |
309 | BATclear(QLOG_cat_query,true); |
310 | BATclear(QLOG_cat_pipe,true); |
311 | BATclear(QLOG_cat_plan,true); |
312 | BATclear(QLOG_cat_mal,true); |
313 | BATclear(QLOG_cat_optimize,true); |
314 | |
315 | BATclear(QLOG_calls_id,true); |
316 | BATclear(QLOG_calls_start,true); |
317 | BATclear(QLOG_calls_stop,true); |
318 | BATclear(QLOG_calls_arguments,true); |
319 | BATclear(QLOG_calls_tuples,true); |
320 | BATclear(QLOG_calls_exec,true); |
321 | BATclear(QLOG_calls_result,true); |
322 | BATclear(QLOG_calls_cpuload,true); |
323 | BATclear(QLOG_calls_iowait,true); |
324 | |
325 | TMsubcommit_list(commitlist, committop); |
326 | MT_lock_unset(&mal_profileLock); |
327 | return MAL_SUCCEED; |
328 | } |
329 | |
330 | str |
331 | QLOGappend(Client cntxt, MalBlkPtr mb, MalStkPtr stk, InstrPtr pci) |
332 | { |
333 | oid *ret = getArgReference_oid(stk,pci,0); |
334 | str *q = getArgReference_str(stk,pci,1); |
335 | str *pipe = getArgReference_str(stk,pci,2); |
336 | str *usr = getArgReference_str(stk,pci,3); |
337 | timestamp *tick = getArgReference_TYPE(stk,pci,4,timestamp); |
338 | oid o; |
339 | InstrPtr sig = getInstrPtr(mb,0); |
340 | char buf[128], *nme= buf; |
341 | str msg; |
342 | |
343 | (void) cntxt; |
344 | msg = initQlog(); |
345 | if( msg) |
346 | return msg; |
347 | snprintf(buf,128,"%s.%s" , getModuleId(sig), getFunctionId(sig)); |
348 | MT_lock_set(&mal_profileLock); |
349 | o = BUNfnd(QLOG_cat_id, &mb->tag); |
350 | if ( o == BUN_NONE){ |
351 | *ret = mb->tag; |
352 | if (BUNappend(QLOG_cat_id,&mb->tag,false) != GDK_SUCCEED || |
353 | BUNappend(QLOG_cat_query,*q,false) != GDK_SUCCEED || |
354 | BUNappend(QLOG_cat_pipe,*pipe,false) != GDK_SUCCEED || |
355 | BUNappend(QLOG_cat_plan,nme,false) != GDK_SUCCEED || |
356 | BUNappend(QLOG_cat_mal,&mb->stop,false) != GDK_SUCCEED || |
357 | BUNappend(QLOG_cat_optimize,&mb->optimize,false) != GDK_SUCCEED || |
358 | BUNappend(QLOG_cat_user,*usr,false) != GDK_SUCCEED || |
359 | BUNappend(QLOG_cat_defined,tick,false) != GDK_SUCCEED) { |
360 | MT_lock_unset(&mal_profileLock); |
361 | throw(MAL, "querylog.append" , SQLSTATE(HY001) MAL_MALLOC_FAIL); |
362 | } |
363 | } |
364 | MT_lock_unset(&mal_profileLock); |
365 | TMsubcommit_list(commitlist, committop); |
366 | return MAL_SUCCEED; |
367 | } |
368 | |
369 | str |
370 | QLOGdefineNaive(void *ret, str *qry, str *opt, int *nr) |
371 | { |
372 | // Nothing else to be done. |
373 | (void) ret; |
374 | (void) qry; |
375 | (void) opt; |
376 | (void) nr; |
377 | return MAL_SUCCEED; |
378 | } |
379 | |
380 | str |
381 | QLOGcontextNaive(void *ret, str *release, str *version, str *revision, str *uri) |
382 | { |
383 | // Nothing else to be done. |
384 | (void) ret; |
385 | (void) release; |
386 | (void) version; |
387 | (void) revision; |
388 | (void) uri; |
389 | return MAL_SUCCEED; |
390 | } |
391 | |
392 | str |
393 | QLOGcall(Client cntxt, MalBlkPtr mb, MalStkPtr stk, InstrPtr pci) |
394 | { |
395 | timestamp *tick1 = getArgReference_TYPE(stk,pci,1,timestamp); |
396 | timestamp *tick2 = getArgReference_TYPE(stk,pci,2,timestamp); |
397 | str *arg = getArgReference_str(stk,pci,3); |
398 | lng *tuples = getArgReference_lng(stk,pci,4); |
399 | lng *xtime = getArgReference_lng(stk,pci,5); |
400 | lng *rtime = getArgReference_lng(stk,pci,6); |
401 | int *cpu = getArgReference_int(stk,pci,7); |
402 | int *iowait = getArgReference_int(stk,pci,8); |
403 | str msg; |
404 | |
405 | (void) cntxt; |
406 | |
407 | msg = initQlog(); |
408 | if( msg) |
409 | return msg; |
410 | if ( *xtime + *rtime < QLOGthreshold) |
411 | return MAL_SUCCEED; |
412 | MT_lock_set(&mal_profileLock); |
413 | if (BUNappend(QLOG_calls_id,&mb->tag,false) != GDK_SUCCEED || |
414 | BUNappend(QLOG_calls_start,tick1,false) != GDK_SUCCEED || |
415 | BUNappend(QLOG_calls_stop,tick2,false) != GDK_SUCCEED || |
416 | BUNappend(QLOG_calls_arguments,*arg,false) != GDK_SUCCEED || |
417 | BUNappend(QLOG_calls_tuples,tuples,false) != GDK_SUCCEED || |
418 | BUNappend(QLOG_calls_exec,xtime,false) != GDK_SUCCEED || |
419 | BUNappend(QLOG_calls_result,rtime,false) != GDK_SUCCEED || |
420 | BUNappend(QLOG_calls_cpuload,cpu,false) != GDK_SUCCEED || |
421 | BUNappend(QLOG_calls_iowait,iowait,false) != GDK_SUCCEED) { |
422 | MT_lock_unset(&mal_profileLock); |
423 | throw(MAL, "querylog.call" , SQLSTATE(HY001) MAL_MALLOC_FAIL); |
424 | } |
425 | MT_lock_unset(&mal_profileLock); |
426 | TMsubcommit_list(commitlist, committop); |
427 | return MAL_SUCCEED; |
428 | } |
429 | |