| 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 | |