Changeset: 465cc1be670d for MonetDB
URL: http://dev.monetdb.org/hg/MonetDB?cmd=changeset;node=465cc1be670d
Modified Files:
clients/mapiclient/tachograph.c
monetdb5/mal/mal.c
monetdb5/mal/mal.h
monetdb5/mal/mal_listing.c
monetdb5/mal/mal_listing.h
monetdb5/mal/mal_profiler.c
monetdb5/optimizer/Makefile.ag
monetdb5/optimizer/opt_pipes.c
monetdb5/optimizer/opt_prelude.c
monetdb5/optimizer/opt_prelude.h
monetdb5/optimizer/opt_support.c
monetdb5/optimizer/opt_support.h
monetdb5/optimizer/opt_wrapper.c
monetdb5/optimizer/optimizer.mal
tools/mserver/mserver5.c
Branch: profiler
Log Message:
JSON based profiling
First step into moving performance monitoring
to the (less humanreadable) JSON format structure.
diffs (truncated from 602 to 300 lines):
diff --git a/clients/mapiclient/tachograph.c b/clients/mapiclient/tachograph.c
--- a/clients/mapiclient/tachograph.c
+++ b/clients/mapiclient/tachograph.c
@@ -750,6 +750,7 @@ update(EventRecord *ev)
fprintf(tachojson,"{\n");
fprintf(tachojson,"\"qid\":\"%s\",\n",currentfunction?currentfunction:"");
fprintf(tachojson,"\"tag\":%d,\n",ev->tag);
+ fprintf(tachojson,"\"thread\":%d,\n",ev->thread);
fprintf(tachojson,"\"pc\":%d,\n",ev->pc);
fprintf(tachojson,"\"time\": "LLFMT",\n",ev->clkticks);
fprintf(tachojson,"\"status\": \"done\",\n");
diff --git a/monetdb5/mal/mal.c b/monetdb5/mal/mal.c
--- a/monetdb5/mal/mal.c
+++ b/monetdb5/mal/mal.c
@@ -12,7 +12,7 @@
char monet_cwd[PATHLENGTH] = { 0 };
size_t monet_memory;
-char monet_characteristics[PATHLENGTH];
+char monetdb_characteristics[PATHLENGTH];
int mal_trace; /* enable profile events on console */
#ifdef HAVE_HGE
int have_hge;
diff --git a/monetdb5/mal/mal.h b/monetdb5/mal/mal.h
--- a/monetdb5/mal/mal.h
+++ b/monetdb5/mal/mal.h
@@ -48,7 +48,7 @@
mal_export char monet_cwd[PATHLENGTH];
mal_export size_t monet_memory;
-mal_export char monet_characteristics[PATHLENGTH];
+mal_export char monetdb_characteristics[PATHLENGTH];
mal_export lng memorypool; /* memory claimed by
concurrent threads */
mal_export int memoryclaims; /* number of threads active
with expensive operations */
mal_export int mal_trace; /* enable profile events on
console */
diff --git a/monetdb5/mal/mal_listing.c b/monetdb5/mal/mal_listing.c
--- a/monetdb5/mal/mal_listing.c
+++ b/monetdb5/mal/mal_listing.c
@@ -16,6 +16,7 @@
#include "mal_utils.h"
#include "mal_exception.h"
#include "mal_listing.h"
+#include "mal_properties.h"
/*
* Since MAL programs can be created on the fly by linked-in query
@@ -376,6 +377,115 @@ instruction2str(MalBlkPtr mb, MalStkPtr
return s;
}
+/* the MAL beautifier is meant to simplify correlation of MAL variables and
+ * the columns in the underlying database.
+ * If the status is set, then we consider the instruction DONE and the result
variables
+ * should be shown as well.
+ */
+static str
+beautyTerm(MalBlkPtr mb, MalStkPtr stk, InstrPtr p, int idx)
+{
+ str s, nme;
+ BAT *b;
+ ValRecord *val;
+ //VarPtr v;
+ char *cv =0;
+ int varid = getArg(p,idx);
+
+ s= GDKmalloc(BUFSIZ);
+ *s = 0;
+
+ if( isVarConstant(mb,varid) ){
+ val =&getVarConstant(mb, varid);
+ VALformat(&cv, val);
+ snprintf(s,BUFSIZ,"%s",cv);
+ if(cv)
+ GDKfree(cv);
+ } else {
+ val = &stk->stk[varid];
+ VALformat(&cv, val);
+ //v = varGetProp(mb, varid, PropertyIndex("schematablecolumn"));
+ nme = getVarName(mb, varid);
+ if ( isaBatType(getArgType(mb,p,idx))){
+ b = BBPquickdesc(abs(stk->stk[varid].val.ival),TRUE);
+ snprintf(s,BUFSIZ,"%s["BUNFMT"]",nme, b?BATcount(b):0);
+ } else
+ snprintf(s,BUFSIZ,"%s",nme);
+ GDKfree(nme);
+ }
+ return s;
+}
+
+str
+instruction2beauty(MalBlkPtr mb, MalStkPtr stk, InstrPtr p, int done)
+{
+ int i;
+ str base, s, t, nme;
+ size_t len= (mb->stop < 1000? 1000: mb->stop) * 128 /* max realistic
line length estimate */;
+
+ base = s = GDKmalloc(len);
+ if ( s == NULL)
+ return s;
+ *s =0;
+ t=s;
+ if (p->token == REMsymbol)
+ return base;
+ // handle the result variables
+ if( done ){
+ for (i = 0; i < p->retc; i++)
+ if (!getVarTmp(mb, getArg(p, i)) || isVarUsed(mb,
getArg(p, i)) || isVarUDFtype(mb,getArg(p,i)))
+ break;
+
+ if (i == p->retc) // no result arguments
+ goto beauty_end;
+
+ /* display optional multi-assignment list */
+ if (p->retc > 1)
+ *t++ = '(';
+
+ for (i = 0; i < p->retc; i++) {
+ nme = beautyTerm(mb, stk, p,i);
+ snprintf(t,(len-(t-base)), "%s", nme);
+ GDKfree(nme);
+ advance(t,base,len);
+ if (i < p->retc - 1)
+ *t++ = ',';
+ }
+ if (p->retc > 1)
+ *t++ = ')';
+
+ }
+ beauty_end:
+ // handle the instruction mapping
+
+ advance(t,base,len);
+ nme = 0;
+ //nme = varGetPropStr(mb, getArg(p,0), PropertyIndex("beautyoperator"));
+ if( nme){
+ snprintf(t, (len-(t-base)),"%s", nme);
+ GDKfree(nme);
+ } else
+ snprintf(t, (len-(t-base)),"%s.%s", getModuleId(p),
getFunctionId(p));
+ advance(t,base,len);
+
+ // handle the arguments, constants should be shown including their
non-default type
+ /* display optional multi-assignment list */
+ *t++ = '(';
+ for (i = 0; i < p->retc; i++) {
+ nme = beautyTerm(mb, stk, p,i);
+ snprintf(t,(len-(t-base)), "%s", nme);
+ GDKfree(nme);
+ advance(t,base,len);
+ if (i < p->retc - 1)
+ *t++ = ',';
+ }
+ *t++ = ')';
+
+ if (t >= s + len)
+ throw(MAL,"instruction2str:","instruction too long");
+ return s;
+}
+
/* Remote execution of MAL calls for more type/property information to be
exchanged */
str
mal2str(MalBlkPtr mb, int first, int last)
diff --git a/monetdb5/mal/mal_listing.h b/monetdb5/mal/mal_listing.h
--- a/monetdb5/mal/mal_listing.h
+++ b/monetdb5/mal/mal_listing.h
@@ -21,6 +21,7 @@ mal_export void printInstruction(stream
mal_export str instructionCall(MalBlkPtr mb, InstrPtr p, str s, str base,
size_t len);
mal_export void promptInstruction(stream *fd, MalBlkPtr mb, MalStkPtr stk,
InstrPtr p, int flg);
mal_export str instruction2str(MalBlkPtr mb, MalStkPtr stl, InstrPtr p, int
hidden);
+mal_export str instruction2beauty(MalBlkPtr mb, MalStkPtr stl, InstrPtr p, int
done);
mal_export str mal2str(MalBlkPtr mb, int first, int last);
mal_export void showMalBlkHistory(stream *out, MalBlkPtr mb);
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
@@ -25,10 +25,12 @@ stream *eventstream = 0;
static int offlineProfiling = FALSE;
static int cachedProfiling = FALSE;
+static int jsonrendering = TRUE;
static str myname = 0;
static oid user = 0;
static void offlineProfilerEvent(MalBlkPtr mb, MalStkPtr stk, InstrPtr pc, int
start, char *alter, char *msg);
+static void offlineProfilerEventJSON(MalBlkPtr mb, MalStkPtr stk, InstrPtr pc,
int start, char *alter, char *msg);
static void cachedProfilerEvent(MalBlkPtr mb, MalStkPtr stk, InstrPtr pc);
static int initTrace(void);
@@ -56,6 +58,8 @@ offlineProfilerHeader(void)
if (eventstream == NULL)
return ;
+ if (jsonrendering)
+ return;
lognew();
logadd("# ");
@@ -106,7 +110,46 @@ static void logsend(char *logbuffer)
error= mnstr_flush(eventstream);
MT_lock_unset(&mal_profileLock, "logsend");
if( showsystem)
- offlineProfilerEvent(0, 0, 0, 0, "system",
monet_characteristics);
+ offlineProfilerEvent(0, 0, 0, 0, "system",
monetdb_characteristics);
+ if ( error) stopProfiler();
+ }
+}
+
+static void logsendJSON(char *logbuffer)
+{ int error=0;
+ char buf[BUFSIZ], *s;
+ size_t len, out;
+
+ if (eventstream) {
+ MT_lock_set(&mal_profileLock, "logsendJSON");
+ if( eventcounter == 0){
+ snprintf(buf,BUFSIZ,"%s\n",monetdb_characteristics);
+ len = strlen(buf);
+ out = mnstr_write(eventstream, buf, 1, len);
+ if( out != len){
+ MT_lock_unset(&mal_profileLock, "logsendJSON");
+ stopProfiler();
+ return;
+ }
+ }
+ eventcounter++;
+ snprintf(buf,BUFSIZ,"%d",eventcounter);
+ s = strchr(logbuffer,(int) ':');
+ if( s == NULL){
+ MT_lock_unset(&mal_profileLock, "logsendJSON");
+ return;
+ }
+
+ strncpy(s+1, buf,strlen(buf));
+ len = strlen(logbuffer);
+ out= mnstr_write(eventstream, logbuffer, 1, len);
+ if( out != len){
+ MT_lock_unset(&mal_profileLock, "logsendJSON");
+ stopProfiler();
+ return;
+ }
+ error= mnstr_flush(eventstream);
+ MT_lock_unset(&mal_profileLock, "logsendJSON");
if ( error) stopProfiler();
}
}
@@ -126,8 +169,10 @@ profilerEvent(oid usr, MalBlkPtr mb, Mal
if (pci == NULL) return;
if (getModuleId(pci) == myname) // ignore profiler commands from
monitoring
return;
- if (offlineProfiling)
+ if (offlineProfiling && !jsonrendering)
offlineProfilerEvent(mb, stk, pci, start,0,0);
+ if (offlineProfiling && jsonrendering)
+ offlineProfilerEventJSON(mb, stk, pci, start,0,0);
if (cachedProfiling && !start )
cachedProfilerEvent(mb, stk, pci);
if ( start && pci->pc ==0)
@@ -253,6 +298,158 @@ offlineProfilerEvent(MalBlkPtr mb, MalSt
logadd("\t]\n"); // end marker
logsend(logbuffer);
}
+
+/* JSON rendering method of performance data. Using the table header as tag,
breaking the complex fields. Example:
+ */
+void
+offlineProfilerEventJSON(MalBlkPtr mb, MalStkPtr stk, InstrPtr pci, int start,
char *alter, char *msg)
+{
+ char logbuffer[LOGLEN], *logbase;
+ int loglen;
+ char ctm[26];
+ time_t clk;
+ struct timeval clock;
+ str stmt, c;
+ char *tbuf;
+ str stmtq;
+
+ if (eventstream == NULL)
+ return ;
+ if (jsonrendering == FALSE)
+ return ;
+
+ if( start) // show when instruction was started
+ clock = pci->clock;
+ else
+ gettimeofday(&clock, NULL);
+ clk = clock.tv_sec;
+
+ /* make basic profile event tuple */
+ lognew();
+ logadd("{ \"event\": ,\n"); // fill in later with the event
counter
+
+ /* without this cast, compilation on Windows fails with
+ * argument of type "long *" is incompatible with parameter of type
"const time_t={__time64_t={__int64}} *"
+ */
+#ifdef HAVE_CTIME_R3
+ tbuf = ctime_r(&clk, ctm, sizeof(ctm));
+#else
+#ifdef HAVE_CTIME_R
+ tbuf = ctime_r(&clk, ctm);
_______________________________________________
checkin-list mailing list
checkin-list@monetdb.org
https://www.monetdb.org/mailman/listinfo/checkin-list
