Changeset: 9e0f6e6d3ef3 for MonetDB
URL: https://dev.monetdb.org/hg/MonetDB/rev/9e0f6e6d3ef3
Modified Files:
clients/Tests/exports.stable.out
monetdb5/mal/mal_client.c
monetdb5/mal/mal_profiler.c
monetdb5/mal/mal_profiler.h
monetdb5/mal/mal_runtime.c
sql/backends/monet5/sql.c
sql/backends/monet5/sql_scenario.c
sql/include/sql_catalog.h
sql/server/sql_mvc.c
sql/storage/sql_storage.h
sql/storage/store.c
Branch: sql_profiler
Log Message:
Improve events structs. Better logging functions. Fix cntxt->query not being
NULL.
diffs (truncated from 706 to 300 lines):
diff --git a/clients/Tests/exports.stable.out b/clients/Tests/exports.stable.out
--- a/clients/Tests/exports.stable.out
+++ b/clients/Tests/exports.stable.out
@@ -1000,7 +1000,6 @@ void freeVariable(MalBlkPtr mb, int vari
void garbageCollector(Client cntxt, MalBlkPtr mb, MalStkPtr stk, int flag);
void garbageElement(Client cntxt, ValPtr v);
const char *generatorRef;
-void genericEvent(str phase, struct GenericEvent e);
MALfcn getAddress(const char *modname, const char *fcnname);
str getArgDefault(MalBlkPtr mb, InstrPtr p, int idx);
ptr getArgReference(MalStkPtr stk, InstrPtr pci, int k);
@@ -1241,7 +1240,7 @@ const char *printRef;
void printSignature(stream *fd, Symbol s, int flg);
void printStack(stream *f, MalBlkPtr mb, MalStkPtr s);
const char *prodRef;
-void profilerEvent(Client cntxt, MalBlkPtr mb, MalStkPtr stk, InstrPtr pci);
+void profilerEvent(MalEvent me, NonMalEvent nme);
void profilerGetCPUStat(lng *user, lng *nice, lng *sys, lng *idle, lng
*iowait);
void profilerHeartbeatEvent(char *alter);
const char *profilerRef;
diff --git a/monetdb5/mal/mal_client.c b/monetdb5/mal/mal_client.c
--- a/monetdb5/mal/mal_client.c
+++ b/monetdb5/mal/mal_client.c
@@ -207,11 +207,12 @@ MCexitClient(Client c)
c->fdout = NULL;
c->fdin = NULL;
}
+ assert(c->query == NULL);
if(malProfileMode > 0) {
lng Tend = GDKusec();
- genericEvent("client_connection",
- (struct GenericEvent)
- { &c->idx, NULL, NULL, NULL,
Tend-(c->session), Tend, 0 });
+ profilerEvent((struct MalEvent) {0},
+ (struct NonMalEvent)
+ {"client_connection", c, Tend, NULL,
0, Tend-(c->session)});
}
setClientContext(NULL);
}
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
@@ -38,15 +38,13 @@ static const char *myname = 0; // avoid
* each key:value pair or as a single line.
* The current stethoscope implementation requires the first option and
* also the term rendering to be set to ''
- */
-
-/* When the MAL block contains a BARRIER block we may end up with tons
+ *
+ * When the MAL block contains a BARRIER block we may end up with tons
* of profiler events. To avoid this, we stop emitting the events
* when we reached the HIGHWATERMARK. Leaving a message in the log.
*/
#define HIGHWATERMARK 5
-
int malProfileMode = 0; /* global flag to indicate profiling mode */
static oid malprofileruser; /* keep track on who has claimed the channel */
@@ -61,14 +59,12 @@ static struct rusage prevUsage;
#define LOGLEN 8192
-// The heart beat events should be sent to all outstanding channels.
static void logjsonInternal(char *logbuffer, bool flush)
{
size_t len;
len = strlen(logbuffer);
if (maleventstream) {
- // upon request the log record is sent over the profile stream
(void) mnstr_write(maleventstream, logbuffer, 1, len);
if (flush)
(void) mnstr_flush(maleventstream, MNSTR_FLUSH_DATA);
@@ -175,89 +171,55 @@ logadd(struct logbuf *logbuf, const char
return true;
}
-/*
- * Generic events refer to all events that are useful to profile since the
- * beginning of a query execution up until the MAL execution. This includes
- * transaction events, SQL parsing, relational tree creation, unnesting,
- * relational optimizers, rel2bin, and MAL optimizers.
- *
- * Profiling a generic event follows the same implementation of ProfilerEvent.
- */
static str
-prepareGenericEvent(str phase, struct GenericEvent e)
+prepareNonMalEvent(Client cntxt, str phase, ulng clk, ulng *tid, int state,
ulng duration)
{
+ oid* user = NULL;
+ oid* tag = NULL;
+ int clientid = -1;
+ str query = NULL;
struct logbuf logbuf = {0};
- uint64_t mclk = (uint64_t)e.clk -
((uint64_t)startup_time.tv_sec*1000000 - (uint64_t)startup_time.tv_usec);
+
+ uint64_t mclk = (uint64_t)clk -
+ ((uint64_t)startup_time.tv_sec*1000000 -
(uint64_t)startup_time.tv_usec);
+
+ if (cntxt) {
+ clientid = cntxt->idx;
+ user = &cntxt->user;
+ if (cntxt->curprg)
+ tag = &cntxt->curprg->def->tag;
+ if (cntxt->query)
+ query = mal_quote(cntxt->query, strlen(cntxt->query));
+ }
- if (logadd(&logbuf,
- "{"
- "\"version\":\""MONETDB_VERSION" (hg id: %s)\""
- ",\"clk\":"ULLFMT
- ",\"mclk\":"ULLFMT
- ",\"thread\":%d"
- ",\"phase\":\"%s\""
- ",\"state\":\"done\""
- ",\"usec\":"ULLFMT
- ",\"clientid\":\"%d\""
- ",\"transactionid\":"ULLFMT
- ",\"tag\":"OIDFMT
- ",\"query\":\"%s\""
- ",\"rc\":\"%d\""
- "}\n",
- mercurial_revision(),
- e.clk,
- mclk,
- THRgettid(),
- phase,
- e.usec,
- e.cid ? *e.cid : 0,
- e.tid ? *e.tid : 0,
- e.tag ? *e.tag : 0,
- e.query ? e.query : "none",
- e.rc))
- return logbuf.logbuffer;
- else {
- logdel(&logbuf);
- return NULL;
- }
+ if (!logadd(&logbuf, "{\"version\":\""MONETDB_VERSION" (hg id: %s)\"",
mercurial_revision()))
+ goto cleanup_and_exit;
+ if (user && !logadd(&logbuf, ", \"userid\":"OIDFMT, *user))
+ goto cleanup_and_exit;
+ if (clientid != -1 && !logadd(&logbuf, ", \"clientsessionid\":\"%d\"",
clientid))
+ goto cleanup_and_exit;
+ if (!logadd(&logbuf, ", \"clk\":"ULLFMT", \"mclk\":"ULLFMT",
\"thread\":%d, \"phase\":\"%s\"",
+ clk, mclk, THRgettid(), phase))
+ goto cleanup_and_exit;
+ if (tid && !logadd(&logbuf, ", \"transactionid\":"ULLFMT, *tid))
+ goto cleanup_and_exit;
+ if (tag && !logadd(&logbuf, ", \"tag\":"OIDFMT, *tag))
+ goto cleanup_and_exit;
+ if (query && !logadd(&logbuf, ", \"query\":\"%s\"", query))
+ goto cleanup_and_exit;
+ if (!logadd(&logbuf, ", \"state\":\"%s\", \"usec\":"ULLFMT"}\n",
+ state==0?"done":"error", duration))
+ goto cleanup_and_exit;
+ GDKfree(query);
+ return logbuf.logbuffer;
+ cleanup_and_exit:
+ GDKfree(query);
+ logdel(&logbuf);
+ return NULL;
}
-static void
-renderGenericEvent(str msg, struct GenericEvent e)
-{
- str event;
- MT_lock_set(&mal_profileLock);
- event = prepareGenericEvent(msg, e);
- if( event ){
- logjsonInternal(event, true);
- free(event);
- }
- MT_lock_unset(&mal_profileLock);
-}
-
-void
-genericEvent(str msg, struct GenericEvent e)
-{
- if( maleventstream )
- renderGenericEvent(msg, e);
-}
-
-/* JSON rendering method of performance data.
- * The eventparser may assume this layout for ease of parsing
- EXAMPLE:
- {
- "event":6 ,
- "thread":3,
- "function":"user.s3_1",
- "pc":1,
- "tag":10397,
- "state":"start",
- "usec":0,
- }
- "stmt":"X_41=0@0:void := querylog.define(\"select count(*) from
tables;\":str,\"default_pipe\":str,30:int);",
-*/
static str
-prepareProfilerEvent(Client cntxt, MalBlkPtr mb, MalStkPtr stk, InstrPtr pci)
+prepareMalEvent(Client cntxt, MalBlkPtr mb, MalStkPtr stk, InstrPtr pci)
{
struct logbuf logbuf;
str c;
@@ -299,15 +261,18 @@ prepareProfilerEvent(Client cntxt, MalBl
if (!logadd(&logbuf,
"{" // fill in
later with the event counter
"\"version\":\""MONETDB_VERSION" (hg id: %s)\""
- ",\"user\":"OIDFMT
+ ",\"userid\":"OIDFMT
+ ",\"clientsessionid\":\"%d\""
",\"clk\":"LLFMT
",\"mclk\":%"PRIu64""
",\"thread\":%d"
+ ",\"phase\":\"mal_engine\""
",\"program\":\"%s.%s\""
",\"pc\":%d"
",\"tag\":"OIDFMT,
mercurial_revision(),
cntxt->user,
+ cntxt->idx,
usec,
microseconds,
THRgettid(),
@@ -315,11 +280,11 @@ prepareProfilerEvent(Client cntxt, MalBl
mb?getPC(mb,pci):0,
stk?stk->tag:0))
goto cleanup_and_exit;
- if( pci->modname && !logadd(&logbuf, ",\"module\":\"%s\"", pci->modname
? pci->modname : ""))
+ if (pci->modname && !logadd(&logbuf, ",\"module\":\"%s\"", pci->modname
? pci->modname : ""))
goto cleanup_and_exit;
- if( pci->fcnname && !logadd(&logbuf, ",\"function\":\"%s\"",
pci->fcnname ? pci->fcnname : ""))
+ if (pci->fcnname && !logadd(&logbuf, ",\"function\":\"%s\"",
pci->fcnname ? pci->fcnname : ""))
goto cleanup_and_exit;
- if( pci->barrier && !logadd(&logbuf, ",\"barrier\":\"%s\"",
operatorName(pci->barrier)))
+ if (pci->barrier && !logadd(&logbuf, ",\"barrier\":\"%s\"",
operatorName(pci->barrier)))
goto cleanup_and_exit;
if ((pci->token < FCNcall || pci->token > PATcall) &&
!logadd(&logbuf, ",\"operator\":\"%s\"",
operatorName(pci->token)))
@@ -339,20 +304,7 @@ prepareProfilerEvent(Client cntxt, MalBl
goto cleanup_and_exit;
if (algo && !logadd(&logbuf, ",\"algorithm\":\"%s\"", algo))
goto cleanup_and_exit;
-
-/* EXAMPLE MAL statement argument decomposition
- * The eventparser may assume this layout for ease of parsing
- {
- ... as above ...
-
"result":{"clk":"173297139,"pc":1,"index":0,,"name":"X_6","type":"void","value":"0@0","eol":0}
- ...
-
"argument":{"clk":173297139,"pc":1,"index":"2","type":"str","value":"\"default_pipe\"","eol":0},
- }
- This information can be used to determine memory footprint and variable life
times.
-*/
-
- // Also show details of the arguments for modelling
- if(mb && pci->modname && pci->fcnname){
+ if (mb && pci->modname && pci->fcnname) {
int j;
if (!logadd(&logbuf, ",\"args\":["))
@@ -548,23 +500,9 @@ prepareProfilerEvent(Client cntxt, MalBl
return NULL;
}
-static void
-renderProfilerEvent(Client cntxt, MalBlkPtr mb, MalStkPtr stk, InstrPtr pci)
-{
- str ev;
- MT_lock_set(&mal_profileLock);
- ev = prepareProfilerEvent(cntxt, mb, stk, pci);
- if( ev ){
- logjsonInternal(ev, true);
- free(ev);
- }
- MT_lock_unset(&mal_profileLock);
-}
-
/* the OS details on cpu load are read from /proc/stat
* We should use an OS define to react to the maximal cores
*/
-
#define MAXCORES 256
#define LASTCPU (MAXCORES - 1)
static struct{
@@ -625,7 +563,7 @@ getCPULoad(char cpuload[BUFSIZ]){
n = strlen(buf);
}
}
- exitloop:
+ exitloop:
if (cpuload == NULL)
return 0;
@@ -699,20 +637,26 @@ profilerHeartbeatEvent(char *alter)
}
_______________________________________________
checkin-list mailing list -- [email protected]
To unsubscribe send an email to [email protected]
