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
checkin-list@monetdb.org
https://www.monetdb.org/mailman/listinfo/checkin-list

Reply via email to