[Self-profiler revamp 2/2]: Profile generator.

The runtime component of the profiler is separated into its own crate.
This crate defines a strongy typed representation of debugging
information associated with each DDlog operator, which includes operator
kind (arrange, join, flatmap, etc), relations and arrangements
that the operator takes as inputs, and the source code location of the
operator.

The crate also implements methods to convert profiling information
accumulated at runtime along with debug info associate with each
operator to JSON and to dump this JSON into and HTML document.

The compiler has been modified to inject debug info into the generated
dataflow program.  As the DDlog runtime instantiates the dataflow graph,
it initializes the profiler with a mapping between DD operators and
DDlog debug info.

In addition, the compiler injects a copy of the program source code into
the generated Rust program.  At runtime the profiler dumps this code in
the `src` folder in the profiling directory on the first call to
`dump_profile`.

Signed-off-by: Leonid Ryzhyk <[email protected]>

Author: ryzhyk

Cargo.toml

@@ -4,6 +4,7 @@ members = [
     "rust/template/ovsdb",
     "rust/template/cmd_parser",
     "rust/template/ddlog_derive",
+    "rust/template/ddlog_profiler",
     "rust/template/differential_datalog",
     "rust/template/differential_datalog_test",
 ]

app/Main.hs

@@ -191,7 +191,7 @@ parseValidate :: (?cfg::Config) => IO ([DatalogModule], DatalogProgram, M.Map Mo
 parseValidate = do
     let Config{..} = ?cfg
     fdata <- readFile confDatalogFile
-    parsed <- runExceptT $ parseDatalogProgram (takeDirectory confDatalogFile:confLibDirs) True fdata confDatalogFile
+    parsed <- runExceptT $ parseDatalogProgram (takeDirectory confDatalogFile:confLibDirs) True fdata confDatalogFile False
     (modules, d, rs_code) <- case parsed of
                                   Left e    -> compilerError e
                                   Right res -> return res 

java/ddlogapi.c

@@ -714,9 +714,73 @@ JNIEXPORT void JNICALL Java_ddlogapi_DDlogAPI_query_1index(
     free(cbinfo);
 }
 
-JNIEXPORT jstring JNICALL Java_ddlogapi_DDlogAPI_ddlog_1profile(
+JNIEXPORT jstring JNICALL Java_ddlogapi_DDlogAPI_ddlog_1dump_1profile(
+    JNIEnv *env, jobject obj, jlong progHandle, jstring label) {
+    const char* label_str = NULL;
+    if (label != NULL) {
+        label_str = (*env)->GetStringUTFChars(env, label, NULL);
+    }
+    char* filename = ddlog_dump_profile((ddlog_prog)progHandle, label_str);
+    if (label != NULL) {
+        (*env)->ReleaseStringUTFChars(env, label, label_str);
+    }
+
+    if (filename == NULL) {
+        throwDDlogException(env, NULL);
+        return NULL;
+    };
+    jstring result = (*env)->NewStringUTF(env, filename);
+    ddlog_string_free(filename);
+    return result;
+}
+
+JNIEXPORT jstring JNICALL Java_ddlogapi_DDlogAPI_ddlog_1arrangement_1size_1profile(
+    JNIEnv *env, jobject obj, jlong progHandle) {
+    char* profile = ddlog_arrangement_size_profile((ddlog_prog)progHandle);
+
+    if (profile == NULL) {
+        throwDDlogException(env, NULL);
+        return NULL;
+    };
+    jstring result = (*env)->NewStringUTF(env, profile);
+    ddlog_string_free(profile);
+    return result;
+}
+
+JNIEXPORT jstring JNICALL Java_ddlogapi_DDlogAPI_ddlog_1peak_1arrangement_1size_1profile(
     JNIEnv *env, jobject obj, jlong progHandle) {
-    char* profile = ddlog_profile((ddlog_prog)progHandle);
+    char* profile = ddlog_peak_arrangement_size_profile((ddlog_prog)progHandle);
+
+    if (profile == NULL) {
+        throwDDlogException(env, NULL);
+        return NULL;
+    };
+    jstring result = (*env)->NewStringUTF(env, profile);
+    ddlog_string_free(profile);
+    return result;
+}
+
+JNIEXPORT jstring JNICALL Java_ddlogapi_DDlogAPI_ddlog_1change_1profile(
+    JNIEnv *env, jobject obj, jlong progHandle) {
+    char* profile = ddlog_change_profile((ddlog_prog)progHandle);
+
+    if (profile == NULL) {
+        throwDDlogException(env, NULL);
+        return NULL;
+    };
+    jstring result = (*env)->NewStringUTF(env, profile);
+    ddlog_string_free(profile);
+    return result;
+}
+
+JNIEXPORT jstring JNICALL Java_ddlogapi_DDlogAPI_ddlog_1cpu_1profile(
+    JNIEnv *env, jobject obj, jlong progHandle) {
+    char* profile = ddlog_cpu_profile((ddlog_prog)progHandle);
+
+    if (profile == NULL) {
+        throwDDlogException(env, NULL);
+        return NULL;
+    };
     jstring result = (*env)->NewStringUTF(env, profile);
     ddlog_string_free(profile);
     return result;

java/ddlogapi/DDlogAPI.java

@@ -54,7 +54,11 @@ native long ddlog_run_with_config(
     static native void ddlog_query_index_from_flatbuf(long hprog, byte[] bytes, int position, FlatBufDescr fb) throws DDlogException;
     static native void ddlog_dump_index_to_flatbuf(long hprog, long idxid, FlatBufDescr fb) throws DDlogException;
     static native int ddlog_clear_relation(long hprog, int relid);
-    static native String ddlog_profile(long hprog);
+    static native String ddlog_dump_profile(long hprog, String label);
+    static native String ddlog_arrangement_size_profile(long hprog);
+    static native String ddlog_peak_arrangement_size_profile(long hprog);
+    static native String ddlog_change_profile(long hprog);
+    static native String ddlog_cpu_profile(long hprog);
     static native void ddlog_enable_cpu_profiling(long hprog, boolean enable) throws DDlogException;
     static native void ddlog_enable_change_profiling(long hprog, boolean enable) throws DDlogException;
     static native long ddlog_log_replace_callback(int module, long old_cbinfo, ObjIntConsumer<String> cb, int max_level);
@@ -649,13 +653,65 @@ public void queryIndex(String index, DDlogRecord key, Consumer<DDlogRecord> call
     }
 
     /**
-     * Returns DDlog program runtime profile as a string.
+     * Dump DDlog program runtime profile to a file;
+     * returns the name of the file.
      *
-     * See <code>ddlog.h: ddlog_profile()</code>
+     * See <code>ddlog.h: ddlog_dump_profile()</code>
      */
-    public String profile() throws DDlogException {
+    public String dumpProfile() throws DDlogException {
         this.checkHandle();
-        return DDlogAPI.ddlog_profile(this.hprog);
+        return DDlogAPI.ddlog_dump_profile(this.hprog, null);
+    }
+
+    /**
+     * Dump DDlog program runtime profile to a file; include <code>label</code>
+     * in the filename; returns the name of the file.
+     *
+     * See <code>ddlog.h: ddlog_dump_profile()</code>
+     */
+    public String dumpProfile(String label) throws DDlogException {
+        this.checkHandle();
+        return DDlogAPI.ddlog_dump_profile(this.hprog, label);
+    }
+
+    /**
+     * Returns DDlog arrangement size profile as a JSON string.
+     *
+     * See <code>ddlog.h: ddlog_arrangement_size_profile()</code>
+     */
+    public String arrangementSizeProfile() throws DDlogException {
+        this.checkHandle();
+        return DDlogAPI.ddlog_arrangement_size_profile(this.hprog);
+    }
+
+    /**
+     * Returns DDlog peak arrangement size profile as a JSON string.
+     *
+     * See <code>ddlog.h: ddlog_arrangement_size_profile()</code>
+     */
+    public String peakArrangementSizeProfile() throws DDlogException {
+        this.checkHandle();
+        return DDlogAPI.ddlog_peak_arrangement_size_profile(this.hprog);
+    }
+
+    /**
+     * Returns DDlog arrangement change profile as a JSON string.
+     *
+     * See <code>ddlog.h: ddlog_change_profile()</code>
+     */
+    public String changeProfile() throws DDlogException {
+        this.checkHandle();
+        return DDlogAPI.ddlog_change_profile(this.hprog);
+    }
+
+    /**
+     * Returns DDlog CPU profile as a JSON string.
+     *
+     * See <code>ddlog.h: ddlog_cpu_profile()</code>
+     */
+    public String cpuProfile() throws DDlogException {
+        this.checkHandle();
+        return DDlogAPI.ddlog_cpu_profile(this.hprog);
     }
 
     /**

java/test/SpanTest.java

@@ -382,8 +382,7 @@ void parseLine(String line)
                             this.api.enableCpuProfiling(false);
                             break;
                         case "":
-                            String profile = this.api.profile();
-                            System.out.println("Profile:");
+                            String profile = this.api.dumpProfile();
                             System.out.println(profile);
                             this.checkSemicolon();
                             break;

java/test1/RedistTest.java

@@ -450,9 +450,8 @@ void parseLine(String line)
                             this.api.enableCpuProfiling(false);
                             break;
                         case "":
-                            String profile = this.api.profile();
-                            System.out.println("Profile:");
-                            System.out.println(profile);
+                            String prof_file = this.api.dumpProfile();
+                            System.out.println(prof_file);
                             this.checkSemicolon();
                             break;
                         default:

java/test_flatbuf1/Test.java

@@ -13,9 +13,12 @@
 import java.util.Arrays;
 import java.io.PrintStream;
 import java.io.UncheckedIOException;
+import java.nio.file.Files;
+import java.nio.file.Paths;
 
 /* Generic DDlog API shared by all programs. */
 import ddlogapi.DDlogAPI;
+import ddlogapi.DDlogConfig;
 import ddlogapi.DDlogCommand;
 import ddlogapi.DDlogRecCommand;
 import ddlogapi.DDlogRecord;
@@ -32,7 +35,9 @@ public class Test {
 
     Test() throws IOException, DDlogException {
         /* Create an instance of the DDlog program with one worker thread. */
-        this.api = new DDlogAPI(1, false);
+        this.api = new DDlogAPI(new DDlogConfig(1, false, 0, DDlogConfig.selfProfiling()), false);
+        api.enableCpuProfiling(true);
+        api.enableChangeProfiling(true);
         api.recordCommands("replay.dat", false);
 
         this.fb_file  = new PrintStream("fb.dump");
@@ -1824,6 +1829,22 @@ void run() throws IOException, DDlogException {
 
         this.fb_file.close();
         this.query_file.close();
+
+        String profile_fname = this.api.dumpProfile();
+        System.out.println("Profile written to '" + profile_fname + "'");
+        String size_profile = this.api.arrangementSizeProfile();
+        Files.write(Paths.get("arrangement_size_profile.json"), size_profile.getBytes());
+        System.out.println("Arrangement size profile written to 'arrangement_size_profile.json'");
+        String peak_profile = this.api.peakArrangementSizeProfile();
+        Files.write(Paths.get("peak_arrangement_size_profile.json"), peak_profile.getBytes());
+        System.out.println("Peak arrangement size profile written to 'peak_arrangement_size_profile.json'");
+        String change_profile = this.api.changeProfile();
+        Files.write(Paths.get("change_profile.json"), change_profile.getBytes());
+        System.out.println("Change profile written to 'change_profile.json'");
+        String cpu_profile = this.api.cpuProfile();
+        Files.write(Paths.get("cpu_profile.json"), cpu_profile.getBytes());
+        System.out.println("CPU profile written to 'cpu_profile.json'");
+
     }
 
     public static void main(String[] args) throws IOException, DDlogException {

package.yaml

@@ -43,6 +43,7 @@ dependencies:
 - githash
 - process
 - aeson
+- utf8-string
 
 library:
   source-dirs: src

rust/template/Cargo.toml

@@ -24,7 +24,7 @@ differential-dataflow = { git = "https://github.com/ddlog-dev/differential-dataf
 #timely = "0.11"
 timely = { git = "https://github.com/ddlog-dev/timely-dataflow", branch = "ddlog-4", default-features = false }
 fnv = "1.0.2"
-once_cell = "1.4.1"
+once_cell = "1.8.0"
 libc = "0.2"
 num-traits = "0.2"
 num = { version = "0.3", features = ["serde"] }
@@ -44,6 +44,9 @@ flatbuffers = { version = "2.0.0", optional = true }
 [dependencies.differential_datalog]
 path = "./differential_datalog"
 
+[dependencies.ddlog_profiler]
+path = "./ddlog_profiler"
+
 [dependencies.cmd_parser]
 path = "./cmd_parser"
 optional = true

rust/template/ddlog.h

@@ -147,13 +147,19 @@ typedef struct {
 typedef struct {
     ddlog_profiling_mode mode;
 
+    /* The following fields are only used if (mode == ddlog_self_profiling) */
+
+    // Directory to store self-profiler output.  Set to NULL to use current
+    // working directory.
+    const char *self_profiler_dir;
+
     /* The following fields are only used if (mode == ddlog_timely_profiling) */
 
     // Destination for the timely log stream.
     ddlog_log_destination timely_destination;
     // Destination for timely progress logging.
     ddlog_log_destination timely_progress_destination;
-    // Differential for Differential Dataflow events.
+    // Destination for Differential Dataflow events.
     ddlog_log_destination differential_destination;
 } ddlog_profiling_config;
 
@@ -815,13 +821,6 @@ extern int ddlog_enable_cpu_profiling(ddlog_prog prog, bool enable);
  */
 extern int ddlog_enable_change_profiling(ddlog_prog prog, bool enable);
 
-/*
- * Returns DDlog program runtime profile as a C string.
- *
- * The returned string must be deallocated using `ddlog_string_free()`.
- */
-extern char* ddlog_profile(ddlog_prog prog);
-
 /*
  * Controls recording of timely operator runtimes. When enabled,
  * DDlog receives timely dataflow events and writes them out to a CSV file
@@ -835,6 +834,65 @@ extern char* ddlog_profile(ddlog_prog prog);
  */
 extern int ddlog_enable_timely_profiling(ddlog_prog prog, bool enable);
 
+/*
+ * Dumps DDlog program runtime profile to a file.  `label` is an optional
+ * label used, along with the current time, to generate a file name to
+ * store the profile.  Set `label` to `NULL`
+ *
+ * Returns absolute path to the generated HTML profile file.  All profiles
+ * for a process (even if the process runs multiple DDlog instances) will
+ * be stored in the same directory.
+ *
+ * The returned string must be deallocated using `ddlog_string_free()`.
+ */
+extern char* ddlog_dump_profile(ddlog_prog prog, const char *label);
+
+/*
+ * Returns arrangement size profile as a JSON string.
+ *
+ * The returned string must be deallocated using `ddlog_string_free()`.
+ *
+ * Fails if the program runs with self-profiler disabled.
+ * Returns `NULL` on error.
+ */
+extern char* ddlog_arrangement_size_profile(ddlog_prog prog);
+
+/*
+ * Returns peak arrangement size profile as a JSON string.
+ *
+ * The returned string must be deallocated using `ddlog_string_free()`.
+ *
+ * Fails if the program runs with self-profiler disabled.
+ * Returns `NULL` on error.
+ */
+extern char* ddlog_peak_arrangement_size_profile(ddlog_prog prog);
+
+/*
+ * Returns arrangement change profile as a JSON string.  The
+ * change profile can be empty if change profiling was never
+ * enabled (using `ddlog_enable_change_profiling()`).  In this
+ * case, the function returns an empty JSON array (`[]`).
+ *
+ * The returned string must be deallocated using `ddlog_string_free()`.
+ *
+ * Fails if the program runs with self-profiler disabled.
+ * Returns `NULL` on error.
+ */
+extern char* ddlog_change_profile(ddlog_prog prog);
+
+/*
+ * Returns DDlog's CPU profile as a JSON string. The CPU
+ * profile can be empty if CPU profiling was never
+ * enabled (using `ddlog_enable_cpu_profiling()`).  In this
+ * case, the function returns an empty JSON array (`[]`).
+ *
+ * The returned string must be deallocated using `ddlog_string_free()`.
+ *
+ * Fails if the program runs with self-profiler disabled.
+ * On error, returns `NULL`.
+ */
+extern char* ddlog_cpu_profile(ddlog_prog prog);
+
 /***********************************************************************
  * Record API
  ***********************************************************************/
@@ -918,7 +976,7 @@ extern void ddlog_free(ddlog_record *rec);
 
 /*
  * Deallocate a C string returned by DDlog
- * (currently only applicable to the string returned by `ddlog_profile()` and
+ * (currently only applicable to the string returned by `ddlog_dump_profile()` and
  * `ddlog_dump_record()`).
  */
 extern void ddlog_string_free(char *s);