Changeset: cd2abaa07bf5 for MonetDB
URL: https://dev.monetdb.org/hg/MonetDB/rev/cd2abaa07bf5
Modified Files:
clients/Tests/MAL-signatures.stable.out
clients/Tests/MAL-signatures.stable.out.int128
monetdb5/mal/mal_client.h
monetdb5/mal/mal_profiler.c
sql/backends/monet5/sql.c
sql/backends/monet5/sql.mal
sql/backends/monet5/sql_upgrades.c
sql/scripts/16_tracelog.sql
sql/test/emptydb/Tests/check.stable.out
sql/test/emptydb/Tests/check.stable.out.32bit
sql/test/emptydb/Tests/check.stable.out.int128
Branch: default
Log Message:
Add the profiler exit event to the tracelog()
diffs (truncated from 505 to 300 lines):
diff --git a/clients/Tests/MAL-signatures.stable.out
b/clients/Tests/MAL-signatures.stable.out
--- a/clients/Tests/MAL-signatures.stable.out
+++ b/clients/Tests/MAL-signatures.stable.out
@@ -9275,7 +9275,7 @@ stdout of test 'MAL-signatures` in direc
[ "sql", "droporderindex", "unsafe pattern
sql.droporderindex(X_0:str, X_1:str, X_2:str):void ", "sql_droporderindex;",
"" ]
[ "sql", "dump_cache", "pattern sql.dump_cache() (X_0:bat[:str],
X_1:bat[:int]) ", "dump_cache;", "" ]
[ "sql", "dump_opt_stats", "pattern sql.dump_opt_stats()
(X_0:bat[:str], X_1:bat[:int]) ", "dump_opt_stats;", "" ]
-[ "sql", "dump_trace", "pattern sql.dump_trace() (X_0:bat[:lng],
X_1:bat[:str]) ", "dump_trace;", "" ]
+[ "sql", "dump_trace", "pattern sql.dump_trace() (X_0:bat[:lng],
X_1:bat[:str], X_2:bat[:str]) ", "dump_trace;", "" ]
[ "sql", "emptybind", "pattern sql.emptybind(X_0:int, X_1:str,
X_2:str, X_3:str, X_4:int) (X_5:bat[:oid], X_6:bat[:any_1]) ",
"mvc_bind_wrap;", "" ]
[ "sql", "emptybind", "pattern sql.emptybind(X_0:int, X_1:str,
X_2:str, X_3:str, X_4:int):bat[:any_1] ", "mvc_bind_wrap;", "" ]
[ "sql", "emptybind", "pattern sql.emptybind(X_0:int, X_1:str,
X_2:str, X_3:str, X_4:int, X_5:int, X_6:int) (X_7:bat[:oid], X_8:bat[:any_1])
", "mvc_bind_wrap;", "" ]
diff --git a/clients/Tests/MAL-signatures.stable.out.int128
b/clients/Tests/MAL-signatures.stable.out.int128
--- a/clients/Tests/MAL-signatures.stable.out.int128
+++ b/clients/Tests/MAL-signatures.stable.out.int128
@@ -12581,7 +12581,7 @@ stdout of test 'MAL-signatures` in direc
[ "sql", "droporderindex", "unsafe pattern
sql.droporderindex(X_0:str, X_1:str, X_2:str):void ", "sql_droporderindex;",
"" ]
[ "sql", "dump_cache", "pattern sql.dump_cache() (X_0:bat[:str],
X_1:bat[:int]) ", "dump_cache;", "" ]
[ "sql", "dump_opt_stats", "pattern sql.dump_opt_stats()
(X_0:bat[:str], X_1:bat[:int]) ", "dump_opt_stats;", "" ]
-[ "sql", "dump_trace", "pattern sql.dump_trace() (X_0:bat[:lng],
X_1:bat[:str]) ", "dump_trace;", "" ]
+[ "sql", "dump_trace", "pattern sql.dump_trace() (X_0:bat[:lng],
X_1:bat[:str], X_2:bat[:str]) ", "dump_trace;", "" ]
[ "sql", "emptybind", "pattern sql.emptybind(X_0:int, X_1:str,
X_2:str, X_3:str, X_4:int) (X_5:bat[:oid], X_6:bat[:any_1]) ",
"mvc_bind_wrap;", "" ]
[ "sql", "emptybind", "pattern sql.emptybind(X_0:int, X_1:str,
X_2:str, X_3:str, X_4:int):bat[:any_1] ", "mvc_bind_wrap;", "" ]
[ "sql", "emptybind", "pattern sql.emptybind(X_0:int, X_1:str,
X_2:str, X_3:str, X_4:int, X_5:int, X_6:int) (X_7:bat[:oid], X_8:bat[:any_1])
", "mvc_bind_wrap;", "" ]
diff --git a/monetdb5/mal/mal_client.h b/monetdb5/mal/mal_client.h
--- a/monetdb5/mal/mal_client.h
+++ b/monetdb5/mal/mal_client.h
@@ -82,6 +82,7 @@ typedef struct CLIENT {
/* The user can request a TRACE SQL statement, calling for collecting
the events locally */
BAT *profticks;
BAT *profstmt;
+ BAT *profevents;
ATOMIC_TYPE lastprint; /* when we last printed the query, to
be depricated */
/*
diff --git a/monetdb5/mal/mal_profiler.c b/monetdb5/mal/mal_profiler.c
--- a/monetdb5/mal/mal_profiler.c
+++ b/monetdb5/mal/mal_profiler.c
@@ -182,8 +182,8 @@ EXAMPLE:
}
"stmt":"X_41=0@0:void := querylog.define(\"select count(*) from
tables;\":str,\"default_pipe\":str,30:int);",
*/
-static void
-renderProfilerEvent(Client cntxt, MalBlkPtr mb, MalStkPtr stk, InstrPtr pci,
int start)
+static str
+prepareProfilerEvent(Client cntxt, MalBlkPtr mb, MalStkPtr stk, InstrPtr pci,
int start)
{
struct logbuf logbuf;
str c;
@@ -199,14 +199,14 @@ renderProfilerEvent(Client cntxt, MalBlk
if( !start && pci->calls > HIGHWATERMARK){
if( pci->calls == 10000 || pci->calls == 100000 || pci->calls
== 1000000 || pci->calls == 10000000)
TRC_WARNING(MAL_SERVER, "Too many calls: %d\n",
pci->calls);
- return;
+ return NULL;
}
/* The stream of events can be complete read by the DBA,
* all other users can only see events assigned to their account
*/
if(malprofileruser!= MAL_ADMIN && malprofileruser != cntxt->user)
- return;
+ return NULL;
logbuf = (struct logbuf) {0};
@@ -235,16 +235,16 @@ renderProfilerEvent(Client cntxt, MalBlk
getModuleId(getInstrPtr(mb, 0)),
getFunctionId(getInstrPtr(mb, 0)),
mb?getPC(mb,pci):0,
stk?stk->tag:0))
- return;
+ return NULL;
if( pci->modname && !logadd(&logbuf, ",\"module\":\"%s\"", pci->modname
? pci->modname : ""))
- return;
+ return NULL;
if( pci->fcnname && !logadd(&logbuf, ",\"function\":\"%s\"",
pci->fcnname ? pci->fcnname : ""))
- return;
+ return NULL;
if( pci->barrier && !logadd(&logbuf, ",\"barrier\":\"%s\"",
operatorName(pci->barrier)))
- return;
+ return NULL;
if ((pci->token < FCNcall || pci->token > PATcall) &&
!logadd(&logbuf, ",\"operator\":\"%s\"",
operatorName(pci->token)))
- return;
+ return NULL;
if (!GDKinmemory(0) && !GDKembedded()) {
char *uuid = NULL;
str c;
@@ -252,16 +252,16 @@ renderProfilerEvent(Client cntxt, MalBlk
ok = logadd(&logbuf, ",\"session\":\"%s\"", uuid);
free(uuid);
if (!ok)
- return;
+ return NULL;
} else
free(c);
}
if (!logadd(&logbuf, ",\"state\":\"%s\",\"usec\":"LLFMT,
start?"start":"done", pci->ticks))
- return;
+ return NULL;
const char *algo = MT_thread_getalgorithm();
if (algo && !logadd(&logbuf, ",\"algorithm\":\"%s\"", algo))
- return;
+ return NULL;
/* EXAMPLE MAL statement argument decomposition
* The eventparser may assume this layout for ease of parsing
@@ -279,7 +279,7 @@ renderProfilerEvent(Client cntxt, MalBlk
int j;
if (!logadd(&logbuf, ",\"args\":["))
- return;
+ return NULL;
for(j=0; j< pci->argc; j++){
int tpe = getVarType(mb, getArg(pci,j));
str tname = 0, cv;
@@ -290,16 +290,16 @@ renderProfilerEvent(Client cntxt, MalBlk
if (j == 0) {
// No comma at the beginning
if (!logadd(&logbuf, "{"))
- return;
+ return NULL;
}
else {
if (!logadd(&logbuf, ",{"))
- return;
+ return NULL;
}
if (!logadd(&logbuf, "\"%s\":%d,\"var\":\"%s\"",
j < pci->retc ? "ret" : "arg",
j,
getVarName(mb, getArg(pci,j))))
- return;
+ return NULL;
c =getVarName(mb, getArg(pci,j));
if(getVarSTC(mb,getArg(pci,j))){
InstrPtr stc = getInstrPtr(mb,
getVarSTC(mb,getArg(pci,j)));
@@ -310,7 +310,7 @@ renderProfilerEvent(Client cntxt, MalBlk
getVarConstant(mb,
getArg(stc,stc->retc +1)).val.sval,
getVarConstant(mb,
getArg(stc,stc->retc +2)).val.sval,
getVarConstant(mb,
getArg(stc,stc->retc +3)).val.sval))
- return;
+ return NULL;
}
if(isaBatType(tpe)){
BAT *d= BATdescriptor(bid =
stk->stk[getArg(pci,j)].val.bval);
@@ -318,7 +318,7 @@ renderProfilerEvent(Client cntxt, MalBlk
ok = logadd(&logbuf, ",\"type\":\"bat[:%s]\"",
tname);
GDKfree(tname);
if (!ok)
- return;
+ return NULL;
if(d) {
BAT *v;
cnt = BATcount(d);
@@ -332,10 +332,10 @@ renderProfilerEvent(Client cntxt, MalBlk
VIEWtparent(d),
d->hseqbase,
v &&
!v->batTransient ? "persistent" : "transient"))
- return;
+ return NULL;
} else {
if (!logadd(&logbuf,
",\"mode\":\"%s\"", (d->batTransient ? "transient" : "persistent")))
- return;
+ return NULL;
}
if (!logadd(&logbuf,
",\"sorted\":%d"
@@ -348,7 +348,7 @@ renderProfilerEvent(Client cntxt, MalBlk
d->tnonil,
d->tnil,
d->tkey))
- return;
+ return NULL;
#define keepprop(NME, LNME)\
{const void *valp = BATgetprop(d, NME); \
if ( valp){\
@@ -359,7 +359,7 @@ if ( valp){\
GDKfree(cv);\
GDKfree(cvquote);\
if (!ok)\
- return;\
+ return NULL;\
}\
}}
keepprop(GDK_MIN_VALUE,"min");
@@ -378,18 +378,18 @@ if ( valp){\
ok = logadd(&logbuf,
",\"file\":\"%s\"", cv + 1);
GDKfree(cv);
if (!ok)
- return;
+ return NULL;
total += cnt * d->twidth;
if (!logadd(&logbuf, ",\"width\":%d",
d->twidth))
- return;
+ return NULL;
/* keeping information about the
individual auxiliary heaps is helpful during analysis. */
if( d->thash && !logadd(&logbuf,
",\"hash\":" LLFMT, (lng) hashinfo(d->thash, d->batCacheid)))
- return;
+ return NULL;
if( d->tvheap && !logadd(&logbuf,
",\"vheap\":" LLFMT, (lng) heapinfo(d->tvheap, d->batCacheid)))
- return;
+ return NULL;
if( d->timprints && !logadd(&logbuf,
",\"imprints\":" LLFMT, (lng) IMPSimprintsize(d)))
- return;
- /* if (!logadd(&logbuf,
"\"debug\":\"%s\",", d->debugmessages)) return; */
+ return NULL;
+ /* if (!logadd(&logbuf,
"\"debug\":\"%s\",", d->debugmessages)) return NULL; */
BBPunfix(d->batCacheid);
}
if (!logadd(&logbuf,
@@ -397,7 +397,7 @@ if ( valp){\
",\"count\":"BUNFMT
",\"size\":" LLFMT,
bid, cnt, total))
- return;
+ return NULL;
} else{
tname = getTypeName(tpe);
ok = logadd(&logbuf,
@@ -406,7 +406,7 @@ if ( valp){\
tname,
isVarConstant(mb, getArg(pci,j)));
GDKfree(tname);
if (!ok)
- return;
+ return NULL;
cv = VALformat(&stk->stk[getArg(pci,j)]);
stmtq = cv ? mal_quote(cv, strlen(cv)) : NULL;
if (stmtq)
@@ -414,21 +414,31 @@ if ( valp){\
GDKfree(cv);
GDKfree(stmtq);
if (!ok)
- return;
+ return NULL;
}
if (!logadd(&logbuf, ",\"eol\":%d",
getVarEolife(mb,getArg(pci,j))))
- return;
- // if (!logadd(&logbuf, ",\"fixed\":%d",
isVarFixed(mb,getArg(pci,j)))) return;
+ return NULL;
+ // if (!logadd(&logbuf, ",\"fixed\":%d",
isVarFixed(mb,getArg(pci,j)))) return NULL;
if (!logadd(&logbuf, "}"))
- return;
+ return NULL;
}
if (!logadd(&logbuf, "]")) // end marker for arguments
- return;
+ return NULL;
}
if (!logadd(&logbuf, "}\n")) // end marker
- return;
- logjsonInternal(logbuf.logbuffer);
- logdel(&logbuf);
+ return NULL;
+ return logbuf.logbuffer;
+}
+
+static void
+renderProfilerEvent(Client cntxt, MalBlkPtr mb, MalStkPtr stk, InstrPtr pci,
int start)
+{
+ str ev;
+ ev = prepareProfilerEvent(cntxt, mb, stk, pci, start);
+ if( ev ){
+ logjsonInternal(ev);
+ GDKfree(ev);
+ }
}
/* the OS details on cpu load are read from /proc/stat
@@ -711,7 +721,9 @@ static void
BBPunfix(cntxt->profticks->batCacheid);
if (cntxt->profstmt)
BBPunfix(cntxt->profstmt->batCacheid);
- cntxt->profticks = cntxt->profstmt = NULL;
+ if (cntxt->profevents)
+ BBPunfix(cntxt->profevents->batCacheid);
+ cntxt->profticks = cntxt->profstmt = cntxt->profevents = NULL;
}
static BAT *
@@ -735,7 +747,8 @@ initTrace(Client cntxt)
}
cntxt->profticks = TRACEcreate(TYPE_lng);
cntxt->profstmt = TRACEcreate(TYPE_str);
- if (cntxt->profticks == NULL || cntxt->profstmt == NULL)
+ cntxt->profevents = TRACEcreate(TYPE_str);
+ if (cntxt->profticks == NULL || cntxt->profstmt == NULL ||
cntxt->profevents == NULL)
_cleanupProfiler(cntxt);
MT_lock_unset(&mal_profileLock);
}
@@ -751,8 +764,9 @@ TRACEtable(Client cntxt, BAT **r)
}
r[0] = COLcopy(cntxt->profticks, cntxt->profticks->ttype, false,
TRANSIENT);
r[1] = COLcopy(cntxt->profstmt, cntxt->profstmt->ttype, false,
TRANSIENT);
+ r[2] = COLcopy(cntxt->profevents, cntxt->profevents->ttype, false,
TRANSIENT);
MT_lock_unset(&mal_profileLock);
- return 2;
+ return 3;
}
_______________________________________________
checkin-list mailing list
[email protected]
https://www.monetdb.org/mailman/listinfo/checkin-list