Changeset: 031bcd3b9fc6 for MonetDB
URL: https://dev.monetdb.org/hg/MonetDB?cmd=changeset;node=031bcd3b9fc6
Modified Files:
        monetdb5/mal/mal_profiler.c
        monetdb5/mal/mal_profiler.h
        monetdb5/modules/mal/profiler.c
        monetdb5/modules/mal/profiler.h
        monetdb5/modules/mal/profiler.mal
        sql/scripts/46_profiler.sql
Branch: default
Log Message:

Introduce sync events

MonetDB reports time since an epoch, which roughly corresponds to the
start time of the server. When we are working with distributed
queries (remote tables), we need to profile two different Monet
servers we probably have different start times.

In order to be able to correlate different time lines from different
servers the sync event contains the current internal clock value and
the number of microseconds since the UNIX Epoch.

This assumes that gettimeofday will produce consistent results in
different servers, and while this assumption might be violated in
practice, the only side effect is that profiling will be inaccurate.


diffs (175 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
@@ -8,11 +8,11 @@
 
 /* (c) M.L. Kersten
  * Performance tracing
- * The stethoscope/tachograph and tomograph performance monitors have 
exclusive access 
- * to a single event stream, which avoids concurrency conflicts amongst 
clients. 
+ * The stethoscope/tachograph and tomograph performance monitors have 
exclusive access
+ * to a single event stream, which avoids concurrency conflicts amongst 
clients.
  * It also avoid cluthered event records on the stream. Since this event 
stream is owned
- * by a client, we should ensure that the profiler is automatically 
- * reset once the owner leaves. 
+ * by a client, we should ensure that the profiler is automatically
+ * reset once the owner leaves.
  */
 #include "monetdb_config.h"
 #include "mal_function.h"
@@ -116,7 +116,7 @@ truncate_string(char *inp)
        return ret;
 }
 
-/* JSON rendering method of performance data. 
+/* JSON rendering method of performance data.
  * The eventparser may assume this layout for ease of parsing
 EXAMPLE:
 {
@@ -421,7 +421,7 @@ getCPULoad(char cpuload[BUFSIZ]){
                        corestat[cpu].system = system;
                        corestat[cpu].idle = idle;
                        corestat[cpu].iowait = iowait;
-               } 
+               }
          skip:
                while (*s && *s != '\n')
                        s++;
@@ -502,7 +502,7 @@ profilerEvent(MalBlkPtr mb, MalStkPtr st
 
 /* The first scheme dumps the events
  * on a stream (and in the pool)
- * The mode encodes two flags: 
+ * The mode encodes two flags:
  * - showing all running instructions
  * - single line json
  */
@@ -533,13 +533,15 @@ openProfilerStream(stream *fd, int mode)
        if( (mode & PROFSHOWRUNNING) > 0){
                for (i = 0; i < MAL_MAXCLIENTS; i++) {
                        c = mal_clients+i;
-                       if ( c->active ) 
+                       if ( c->active )
                                for(j = 0; j <THREADS; j++)
                                if( c->inprogress[j].mb)
                                /* show the event */
                                        profilerEvent(c->inprogress[j].mb, 
c->inprogress[j].stk, c->inprogress[j].pci, 1, c->username);
                }
        }
+       /* Syncronize at start up */
+       syncEvent();
        return MAL_SUCCEED;
 }
 
@@ -618,7 +620,7 @@ stopTrace(str path)
                offlinestore =0;
        }
        MT_lock_unset(&mal_profileLock );
-       
+
        malProfileMode = eventstream != NULL;
        sqlProfiling = FALSE;
        return MAL_SUCCEED;
@@ -817,7 +819,7 @@ initTrace(void)
                TRACE_id_minflt == NULL ||
                TRACE_id_majflt == NULL ||
                TRACE_id_nvcsw == NULL ||
-               TRACE_id_thread == NULL 
+               TRACE_id_thread == NULL
        )
                _cleanupProfiler();
        else
@@ -1079,3 +1081,30 @@ void initHeartbeat(void)
        }
 }
 
+str
+syncEvent(void)
+{
+       char logbuffer[LOGLEN], *logbase;
+       int loglen;
+       struct timeval curr_time;
+       lng usec = GDKusec();
+       uint64_t clock_time;
+
+       gettimeofday(&curr_time, NULL);
+       clock_time = curr_time.tv_sec*1000000 + (curr_time.tv_usec == -1 ? 0 : 
curr_time.tv_usec);
+
+       lognew();
+       logadd("{%s", prettify);
+       logadd("\"source\":\"sync\",%s", prettify);
+       if(mal_session_uuid)
+               logadd("\"session\":\"%s\",%s", mal_session_uuid, prettify);
+       // the state field is not really needed, but marvin 1.0 explicitly
+       // searches for it.
+       logadd("\"state\":\"callback\",%s", prettify);
+       logadd("\"clk\":"LLFMT",%s", usec, prettify);
+       logadd("\"time\":%"PRIu64",%s", clock_time, prettify);
+       logadd("}\n");
+       logjsonInternal(logbuffer);
+
+       return MAL_SUCCEED;
+}
diff --git a/monetdb5/mal/mal_profiler.h b/monetdb5/mal/mal_profiler.h
--- a/monetdb5/mal/mal_profiler.h
+++ b/monetdb5/mal/mal_profiler.h
@@ -56,4 +56,6 @@ mal_export lng getDiskWrites(void);
 mal_export lng getUserTime(void);
 mal_export lng getSystemTime(void);
 mal_export void profilerGetCPUStat(lng *user, lng *nice, lng *sys, lng *idle, 
lng *iowait);
+
+mal_export str syncEvent(void);
 #endif
diff --git a/monetdb5/modules/mal/profiler.c b/monetdb5/modules/mal/profiler.c
--- a/monetdb5/modules/mal/profiler.c
+++ b/monetdb5/modules/mal/profiler.c
@@ -83,7 +83,7 @@ CMDstartTrace(void *res)
 }
 
 // if you haven't started the stethoscope
-// then the output is saved in a file 
+// then the output is saved in a file
 str
 CMDstartTracePath(void *res, str *path)
 {
@@ -216,3 +216,10 @@ CMDcpuloadPercentage(int *cycles, int *i
        }
        return MAL_SUCCEED;
 }
+
+str
+CMDsyncEvent(void *ret)
+{
+       (void)ret;
+       return syncEvent();
+}
diff --git a/monetdb5/modules/mal/profiler.h b/monetdb5/modules/mal/profiler.h
--- a/monetdb5/modules/mal/profiler.h
+++ b/monetdb5/modules/mal/profiler.h
@@ -48,4 +48,6 @@ mal_export str CMDgetUserTime(lng *ret);
 mal_export str CMDgetSystemTime(lng *ret);
 mal_export str CMDcpustats(lng *user, lng *nice, lng *sys, lng *idle, lng 
*iowait);
 mal_export str CMDcpuloadPercentage(int *cycles, int *io, lng *user, lng 
*nice, lng *sys, lng *idle, lng *iowait);
+
+mal_export str CMDsyncEvent(void *ret);
 #endif  /* _PROFILER_*/
diff --git a/monetdb5/modules/mal/profiler.mal 
b/monetdb5/modules/mal/profiler.mal
--- a/monetdb5/modules/mal/profiler.mal
+++ b/monetdb5/modules/mal/profiler.mal
@@ -83,3 +83,7 @@ comment "Extract cpu statistics from the
 command cpuload(user:lng, nice:lng, 
sys:lng,idle:lng,iowait:lng)(cycles:int,io:int)
 address CMDcpuloadPercentage
 comment "Calculate the average cpu load percentage and io waiting times";
+
+command sync()
+address CMDsyncEvent
+comment "Generate a syncronization event"
diff --git a/sql/scripts/46_profiler.sql b/sql/scripts/46_profiler.sql
--- a/sql/scripts/46_profiler.sql
+++ b/sql/scripts/46_profiler.sql
@@ -13,3 +13,5 @@ create procedure profiler.stop() externa
 create procedure profiler.setheartbeat(beat int) external name 
profiler.setheartbeat;
 create function profiler.getlimit() returns integer external name 
profiler.getlimit;
 create procedure  profiler.setlimit(lim integer) external name 
profiler.setlimit;
+
+create procedure profiler.sync() external name profiler.sync;
_______________________________________________
checkin-list mailing list
checkin-list@monetdb.org
https://www.monetdb.org/mailman/listinfo/checkin-list

Reply via email to