Changeset: 854ec21bfdcc for MonetDB
URL: https://dev.monetdb.org/hg/MonetDB/rev/854ec21bfdcc
Branch: Jun2020-mmt
Log Message:
Merge with Jun2020 branch.
diffs (truncated from 742 to 300 lines):
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
@@ -31,17 +31,18 @@
#include <string.h>
-static str myname = 0; // avoid tracing the profiler module
+static const char *myname = 0; // avoid tracing the profiler module
/* The JSON rendering can be either using '\n' separators between
* 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 ''
+ * also the term rendering to be set to ''
*/
/* 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. */
+ * when we reached the HIGHWATERMARK. Leaving a message in the log.
+ */
#define HIGHWATERMARK 5
@@ -58,242 +59,378 @@ static struct rusage prevUsage;
#endif
#define LOGLEN 8192
-#define lognew() loglen = 0; logbase = logbuffer; *logbase = 0;
-
-#define logadd(...)
\
- do {
\
- char tmp_buff[LOGLEN];
\
- int tmp_len = 0;
\
- tmp_len = snprintf(tmp_buff, LOGLEN, __VA_ARGS__);
\
- if (loglen + tmp_len < LOGLEN)
\
- loglen += snprintf(logbase+loglen, LOGLEN - loglen,
__VA_ARGS__); \
- else {
\
- logjsonInternal(logbuffer);
\
- lognew();
\
- loglen += snprintf(logbase+loglen, LOGLEN - loglen,
__VA_ARGS__); \
- }
\
- } while (0)
// The heart beat events should be sent to all outstanding channels.
-static void logjsonInternal(char *logbuffer)
+static void logjsonInternal(char *logbuffer, bool flush)
{
size_t len;
len = strlen(logbuffer);
- MT_lock_set(&mal_profileLock);
if (maleventstream) {
- // upon request the log record is sent over the profile stream
+ // upon request the log record is sent over the profile stream
(void) mnstr_write(maleventstream, logbuffer, 1, len);
- (void) mnstr_flush(maleventstream);
+ if (flush)
+ (void) mnstr_flush(maleventstream);
}
- MT_lock_unset(&mal_profileLock);
+}
+
+/*
+ * We use a buffer (`logbuffer`) where we incrementally create the output JSON
object. Initially we allocate LOGLEN (8K)
+ * bytes and we keep the capacity of the buffer (`logcap`) and the length of
the current string (`loglen`).
+ *
+ * We use the `logadd` function to add data to our buffer (usually key-value
pairs). This macro offers an interface similar
+ * to printf.
+ *
+ * The first snprintf bellow happens in a statically allocated buffer that
might be much smaller than logcap. We do not
+ * care. We only need to perform this snprintf to get the actual length of the
string that is to be produced.
+ *
+ * There are three cases:
+ *
+ * 1. The new string fits in the current buffer -> we just update the buffer
+ *
+ * 2. The new string does not fit in the current buffer, but is smaller than
the capacity of the buffer -> we output the
+ * current contents of the buffer and start at the beginning.
+ *
+ * 3. The new string exceeds the current capacity of the buffer -> we output
the current contents and reallocate the
+ * buffer. The new capacity is 1.5 times the length of the new string.
+ */
+struct logbuf {
+ char *logbuffer;
+ char *logbase;
+ size_t loglen;
+ size_t logcap;
+};
+
+static inline void
+lognew(struct logbuf *logbuf)
+{
+ logbuf->loglen = 0;
+ logbuf->logbase = logbuf->logbuffer;
+ *logbuf->logbase = 0;
+}
+
+static inline void
+logdel(struct logbuf *logbuf)
+{
+ free(logbuf->logbuffer);
}
-static char *
-truncate_string(char *inp)
+static bool logadd(struct logbuf *logbuf,
+ _In_z_ _Printf_format_string_ const char
*fmt, ...)
+ __attribute__((__format__(__printf__, 2, 3)))
+ __attribute__((__warn_unused_result__));
+static bool
+logadd(struct logbuf *logbuf, const char *fmt, ...)
{
- size_t len;
- char *ret;
- size_t ret_len = LOGLEN/2;
- size_t padding = 64;
+ char tmp_buff[LOGLEN];
+ int tmp_len;
+ va_list va;
+ va_list va2;
- len = strlen(inp);
- ret = (char *)GDKmalloc(ret_len + 1);
- if (ret == NULL) {
- return NULL;
+ va_start(va, fmt);
+ va_copy(va2, va); /* we will need it again */
+ tmp_len = vsnprintf(tmp_buff, sizeof(tmp_buff), fmt, va);
+ if (tmp_len < 0) {
+ logdel(logbuf);
+ va_end(va);
+ va_end(va2);
+ return false;
}
-
- snprintf(ret, ret_len + 1, "%.*s...<truncated>...%.*s",
- (int) (ret_len/2), inp, (int) (ret_len/2 - padding),
- inp + (len - ret_len/2 + padding));
-
- return ret;
+ if (logbuf->loglen + (size_t) tmp_len >= logbuf->logcap) {
+ if ((size_t) tmp_len >= logbuf->logcap) {
+ /* includes first time when logbuffer == NULL and
logcap = 0 */
+ char *alloc_buff;
+ if (logbuf->loglen > 0)
+ logjsonInternal(logbuf->logbuffer, false);
+ logbuf->logcap = (size_t) tmp_len + (size_t) tmp_len/2;
+ if (logbuf->logcap < LOGLEN)
+ logbuf->logcap = LOGLEN;
+ alloc_buff = realloc(logbuf->logbuffer, logbuf->logcap);
+ if (alloc_buff == NULL) {
+ TRC_ERROR(MAL_SERVER, "Profiler JSON buffer
reallocation failure\n");
+ logdel(logbuf);
+ va_end(va);
+ va_end(va2);
+ return false;
+ }
+ logbuf->logbuffer = alloc_buff;
+ lognew(logbuf);
+ } else {
+ logjsonInternal(logbuf->logbuffer, false);
+ lognew(logbuf);
+ }
+ }
+ logbuf->loglen += vsnprintf(logbuf->logbase + logbuf->loglen,
+ logbuf->logcap
- logbuf->loglen,
+ fmt, va2);
+ va_end(va);
+ va_end(va2);
+ return true;
}
/* 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);",
+ 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 void
-renderProfilerEvent(Client cntxt, MalBlkPtr mb, MalStkPtr stk, InstrPtr pci,
int start)
+prepareProfilerEvent(Client cntxt, MalBlkPtr mb, MalStkPtr stk, InstrPtr pci,
int start)
{
- char logbuffer[LOGLEN], *logbase;
- size_t loglen;
+ struct logbuf logbuf;
str c;
str stmtq;
lng usec;
uint64_t microseconds;
+ bool ok;
/* ignore generation of events for instructions that are called too
often
* they may appear when BARRIER blocks are executed
* The default parameter should be sufficient for most practical cases.
- */
+ */
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;
}
-/* The stream of events can be complete read by the DBA,
- * all other users can only see events assigned to their account
- */
+ /* 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;
+ logbuf = (struct logbuf) {0};
+
usec= pci->clock;
microseconds = (uint64_t)usec - ((uint64_t)startup_time.tv_sec*1000000
- (uint64_t)startup_time.tv_usec);
/* make profile event tuple */
- lognew();
- logadd("{"); // fill in later with the event counter
/* TODO: This could probably be optimized somehow to avoid the
* function call to mercurial_revision().
*/
// No comma at the beginning
- logadd("\"version\":\""VERSION" (hg id: %s)\"", mercurial_revision());
- logadd(",\"user\":"OIDFMT, cntxt->user);
- logadd(",\"clk\":"LLFMT, usec);
- logadd(",\"mclk\":%"PRIu64"", microseconds);
- logadd(",\"thread\":%d", THRgettid());
- logadd(",\"program\":\"%s.%s\"", getModuleId(getInstrPtr(mb, 0)),
getFunctionId(getInstrPtr(mb, 0)));
- logadd(",\"pc\":%d", mb?getPC(mb,pci):0);
- logadd(",\"tag\":"OIDFMT, stk?stk->tag:0);
- if( pci->modname)
- logadd(",\"module\":\"%s\"", pci->modname ? pci->modname : "");
- if( pci->fcnname)
- logadd(",\"function\":\"%s\"", pci->fcnname ? pci->fcnname :
"");
- if( pci->barrier)
- logadd(",\"barrier\":\"%s\"", operatorName(pci->barrier));
- if( pci->token < FCNcall || pci->token > PATcall)
- logadd(",\"operator\":\"%s\"", operatorName(pci->token));
- if (!GDKinmemory()) {
- char *uuid;
+ if (!logadd(&logbuf,
+ "{" // fill in
later with the event counter
+ "\"version\":\""VERSION" (hg id: %s)\""
+ ",\"user\":"OIDFMT
+ ",\"clk\":"LLFMT
+ ",\"mclk\":%"PRIu64""
+ ",\"thread\":%d"
+ ",\"program\":\"%s.%s\""
+ ",\"pc\":%d"
+ ",\"tag\":"OIDFMT,
+ mercurial_revision(),
+ cntxt->user,
+ usec,
+ microseconds,
+ THRgettid(),
+ getModuleId(getInstrPtr(mb, 0)),
getFunctionId(getInstrPtr(mb, 0)),
+ mb?getPC(mb,pci):0,
+ stk?stk->tag:0))
+ return;
+ if( pci->modname && !logadd(&logbuf, ",\"module\":\"%s\"", pci->modname
? pci->modname : ""))
+ return;
+ if( pci->fcnname && !logadd(&logbuf, ",\"function\":\"%s\"",
pci->fcnname ? pci->fcnname : ""))
+ return;
+ if( pci->barrier && !logadd(&logbuf, ",\"barrier\":\"%s\"",
operatorName(pci->barrier)))
+ return;
+ if ((pci->token < FCNcall || pci->token > PATcall) &&
+ !logadd(&logbuf, ",\"operator\":\"%s\"",
operatorName(pci->token)))
+ return;
+ if (!GDKinmemory()) {
+ char *uuid = NULL;
str c;
if ((c = msab_getUUID(&uuid)) == NULL) {
- logadd(",\"session\":\"%s\"", uuid);
+ ok = logadd(&logbuf, ",\"session\":\"%s\"", uuid);
free(uuid);
+ if (!ok)
+ return;
} else
free(c);
_______________________________________________
checkin-list mailing list -- [email protected]
To unsubscribe send an email to [email protected]
