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 | /* Author(s) M.L. Kersten |
10 | * The MAL Runtime Profiler and system queue |
11 | * This little helper module is used to perform instruction based profiling. |
12 | * The QRYqueue is only update at the start/finish of a query. |
13 | * It is also the place to keep track on the number of workers |
14 | * The current could relies on a scan rather than a hash. |
15 | */ |
16 | |
17 | #include "monetdb_config.h" |
18 | #include "mal_utils.h" |
19 | #include "mal_runtime.h" |
20 | #include "mal_interpreter.h" |
21 | #include "mal_function.h" |
22 | #include "mal_profiler.h" |
23 | #include "mal_listing.h" |
24 | #include "mal_authorize.h" |
25 | #include "mal_resource.h" |
26 | #include "mal_private.h" |
27 | |
28 | |
29 | QueryQueue QRYqueue; |
30 | lng qtop; |
31 | static lng qsize; |
32 | static oid qtag= 1; // A unique query identifier |
33 | |
34 | void |
35 | mal_runtime_reset(void) |
36 | { |
37 | GDKfree(QRYqueue); |
38 | QRYqueue = 0; |
39 | qtop = 0; |
40 | qsize = 0; |
41 | qtag= 1; |
42 | } |
43 | |
44 | static str |
45 | isaSQLquery(MalBlkPtr mb){ |
46 | int i; |
47 | InstrPtr p; |
48 | if (mb) |
49 | for ( i = 1; i< mb->stop; i++){ |
50 | p = getInstrPtr(mb,i); |
51 | if ( getModuleId(p) && idcmp(getModuleId(p), "querylog" ) == 0 && idcmp(getFunctionId(p),"define" )==0) |
52 | return getVarConstant(mb,getArg(p,1)).val.sval; |
53 | } |
54 | return NULL; |
55 | } |
56 | |
57 | /* |
58 | * Manage the runtime profiling information |
59 | */ |
60 | |
61 | void |
62 | runtimeProfileInit(Client cntxt, MalBlkPtr mb, MalStkPtr stk) |
63 | { |
64 | lng i; |
65 | str q; |
66 | QueryQueue tmp; |
67 | |
68 | MT_lock_set(&mal_delayLock); |
69 | tmp = QRYqueue; |
70 | if ( QRYqueue == 0) |
71 | QRYqueue = (QueryQueue) GDKzalloc( sizeof (struct QRYQUEUE) * (size_t) (qsize= 1024)); |
72 | else if ( qtop + 1 == qsize ) |
73 | QRYqueue = (QueryQueue) GDKrealloc( QRYqueue, sizeof (struct QRYQUEUE) * (size_t) (qsize += 256)); |
74 | if ( QRYqueue == NULL){ |
75 | addMalException(mb,"runtimeProfileInit" MAL_MALLOC_FAIL); |
76 | GDKfree(tmp); |
77 | MT_lock_unset(&mal_delayLock); |
78 | return; |
79 | } |
80 | // check for recursive call, which does not change the number of workers |
81 | for( i = 0; i < qtop; i++) |
82 | if ( QRYqueue[i].mb == mb && stk->up == QRYqueue[i].stk){ |
83 | QRYqueue[i].stk = stk; |
84 | mb->tag = stk->tag = qtag++; |
85 | MT_lock_unset(&mal_delayLock); |
86 | return; |
87 | } |
88 | |
89 | // add new invocation |
90 | if (i == qtop) { |
91 | QRYqueue[i].mb = mb; |
92 | QRYqueue[i].tag = qtag++; |
93 | QRYqueue[i].stk = stk; // for status pause 'p'/running '0'/ quiting 'q' |
94 | QRYqueue[i].start = time(0); |
95 | QRYqueue[i].runtime = mb->runtime; // the estimated execution time |
96 | q = isaSQLquery(mb); |
97 | QRYqueue[i].query = q? GDKstrdup(q):0; |
98 | QRYqueue[i].status = "running" ; |
99 | QRYqueue[i].cntxt = cntxt; |
100 | stk->tag = mb->tag = QRYqueue[i].tag; |
101 | } |
102 | qtop += i == qtop; |
103 | MT_lock_unset(&mal_delayLock); |
104 | } |
105 | |
106 | /* We should keep a short list of previously executed queries/client for inspection. |
107 | * Returning from a recursive call does not change the number of workers. |
108 | */ |
109 | |
110 | void |
111 | runtimeProfileFinish(Client cntxt, MalBlkPtr mb, MalStkPtr stk) |
112 | { |
113 | lng i,j; |
114 | |
115 | (void) cntxt; |
116 | (void) mb; |
117 | |
118 | MT_lock_set(&mal_delayLock); |
119 | for( i=j=0; i< qtop; i++) |
120 | if ( QRYqueue[i].stk != stk) |
121 | QRYqueue[j++] = QRYqueue[i]; |
122 | else { |
123 | if( stk->up){ |
124 | // recursive call |
125 | QRYqueue[i].stk = stk->up; |
126 | mb->tag = stk->tag; |
127 | MT_lock_unset(&mal_delayLock); |
128 | return; |
129 | } |
130 | QRYqueue[i].status = "finished" ; |
131 | GDKfree(QRYqueue[i].query); |
132 | QRYqueue[i].cntxt = 0; |
133 | QRYqueue[i].tag = 0; |
134 | QRYqueue[i].query = 0; |
135 | QRYqueue[i].status =0; |
136 | QRYqueue[i].progress =0; |
137 | QRYqueue[i].stk =0; |
138 | QRYqueue[i].mb =0; |
139 | } |
140 | |
141 | qtop = j; |
142 | QRYqueue[qtop].query = NULL; /* sentinel for SYSMONqueue() */ |
143 | MT_lock_unset(&mal_delayLock); |
144 | } |
145 | |
146 | /* When the client connection is closed, then also the queue should be updated */ |
147 | void |
148 | finishSessionProfiler(Client cntxt) |
149 | { |
150 | lng i,j; |
151 | |
152 | (void) cntxt; |
153 | |
154 | MT_lock_set(&mal_delayLock); |
155 | for( i=j=0; i< qtop; i++) |
156 | if ( QRYqueue[i].cntxt != cntxt) |
157 | QRYqueue[j++] = QRYqueue[i]; |
158 | else { |
159 | GDKfree(QRYqueue[i].query); |
160 | QRYqueue[i].cntxt = 0; |
161 | QRYqueue[i].tag = 0; |
162 | QRYqueue[i].query = 0; |
163 | QRYqueue[i].progress =0; |
164 | QRYqueue[i].status =0; |
165 | QRYqueue[i].stk =0; |
166 | QRYqueue[i].mb =0; |
167 | } |
168 | qtop = j; |
169 | MT_lock_unset(&mal_delayLock); |
170 | } |
171 | |
172 | /* |
173 | * Each MAL instruction is executed by a single thread, which means we can |
174 | * keep a simple working set around to make Stethscope attachement easy. |
175 | * It can also be used to later shutdown each thread safely. |
176 | */ |
177 | Workingset workingset[THREADS]; |
178 | |
179 | void |
180 | runtimeProfileBegin(Client cntxt, MalBlkPtr mb, MalStkPtr stk, InstrPtr pci, RuntimeProfile prof) |
181 | { |
182 | int tid = THRgettid(); |
183 | |
184 | assert(pci); |
185 | /* keep track on the instructions taken in progress for stethoscope*/ |
186 | if( tid < THREADS){ |
187 | MT_lock_set(&mal_delayLock); |
188 | workingset[tid].cntxt = cntxt; |
189 | workingset[tid].mb = mb; |
190 | workingset[tid].stk = stk; |
191 | workingset[tid].pci = pci; |
192 | MT_lock_unset(&mal_delayLock); |
193 | } |
194 | /* always collect the MAL instruction execution time */ |
195 | pci->clock = prof->ticks = GDKusec(); |
196 | |
197 | /* emit the instruction upon start as well */ |
198 | if(malProfileMode > 0 ) |
199 | profilerEvent(cntxt, mb, stk, pci, TRUE); |
200 | } |
201 | |
202 | void |
203 | runtimeProfileExit(Client cntxt, MalBlkPtr mb, MalStkPtr stk, InstrPtr pci, RuntimeProfile prof) |
204 | { |
205 | int tid = THRgettid(); |
206 | lng ticks = GDKusec(); |
207 | |
208 | /* keep track on the instructions in progress*/ |
209 | if ( tid < THREADS) { |
210 | MT_lock_set(&mal_delayLock); |
211 | workingset[tid].mb = 0; |
212 | workingset[tid].stk = 0; |
213 | workingset[tid].pci = 0; |
214 | MT_lock_unset(&mal_delayLock); |
215 | } |
216 | |
217 | /* always collect the MAL instruction execution time */ |
218 | pci->clock = ticks; |
219 | pci->ticks = ticks - prof->ticks; |
220 | pci->totticks += pci->ticks; |
221 | pci->calls++; |
222 | |
223 | if(malProfileMode > 0 ) |
224 | profilerEvent(cntxt, mb, stk, pci, FALSE); |
225 | if( cntxt->sqlprofiler ) |
226 | sqlProfilerEvent(cntxt, mb, stk, pci); |
227 | if( malProfileMode < 0){ |
228 | /* delay profiling until you encounter start of MAL function */ |
229 | if( getInstrPtr(mb,0) == pci) |
230 | malProfileMode = 1; |
231 | } |
232 | } |
233 | |
234 | /* |
235 | * For performance evaluation it is handy to estimate the |
236 | * amount of bytes produced by an instruction. |
237 | * The actual amount is harder to guess, because an instruction |
238 | * may trigger a side effect, such as creating a hash-index. |
239 | * Side effects are ignored. |
240 | */ |
241 | |
242 | lng |
243 | getBatSpace(BAT *b){ |
244 | lng space=0; |
245 | if( b == NULL) |
246 | return 0; |
247 | space += BATcount(b) * b->twidth; |
248 | if( space){ |
249 | if( b->tvheap) space += heapinfo(b->tvheap, b->batCacheid); |
250 | space += hashinfo(b->thash, b->batCacheid); |
251 | space += IMPSimprintsize(b); |
252 | } |
253 | return space; |
254 | } |
255 | |
256 | lng getVolume(MalStkPtr stk, InstrPtr pci, int rd) |
257 | { |
258 | int i, limit; |
259 | lng vol = 0; |
260 | BAT *b; |
261 | |
262 | if( stk == NULL) |
263 | return 0; |
264 | limit = rd ? pci->argc : pci->retc; |
265 | i = rd ? pci->retc : 0; |
266 | |
267 | for (; i < limit; i++) { |
268 | if (stk->stk[getArg(pci, i)].vtype == TYPE_bat) { |
269 | oid cnt = 0; |
270 | |
271 | b = BBPquickdesc(stk->stk[getArg(pci, i)].val.bval, true); |
272 | if (b == NULL) |
273 | continue; |
274 | cnt = BATcount(b); |
275 | /* Usually reading views cost as much as full bats. |
276 | But when we output a slice that is not the case. */ |
277 | if( rd) |
278 | vol += (!isVIEW(b) && !VIEWtparent(b)) ? tailsize(b, cnt) : 0; |
279 | else |
280 | if( !isVIEW(b)) |
281 | vol += tailsize(b, cnt); |
282 | } |
283 | } |
284 | return vol; |
285 | } |
286 | |