[Profiling] First tests & visualization (#2275)

This PR contains:
- Some very simple tests for the profiler to understand/debug where
"extra" cycles are happening
- `convert-dump.py`: a script generating a JSON in Google's trace file
format to visualize info from the profiler
- Changes to `get-profile-counts-info.sh` (wrapper script) to generate
the visualization JSON & reorganize generated files

The CI fails even when tests pass locally and I'm having a bit of
trouble figuring this out (hence the tests being commented out in
`.github/workflows/rust.yml`) but I will get back to this soon! Some big
bug fixes and re-organizing my VCD parsing script (WIP; coming in the
next PR) just seem like bigger priority than fixing the CI for now.

Please let me know if there's anything I should change/improve/fix!

## Usage/Differences

### Tests

To run profiler tests, run:
```
runt -i profiler --max-futures 1
```
The current version of my profiling pipeline should be run sequentially,
hence the `--max-futures 1`.

### Visualization

To profile and obtain visualization information for a Calyx program,
run:
```
bash <CALYX_DIR>/tools/profiler/get-profile-counts-info.sh <CALYX_FILE> <SIM_DATA_JSON>
```
where `CALYX_DIR` is the root directory of this repo, `CALYX_FILE` is
the program to profile, and `SIM_DATA_JSON` is the memory data to feed
into the simulation.

As the console output should say, the visualization data will be written
to `<CALYX_DIR>/tools/profiler/tools/profiler/data/tmp/visual.json`. You
can then feed this JSON file into https://ui.perfetto.dev/ to see the
visualization! In the visualization, each cycle is represented by 100ms.

.github/workflows/rust.yml

@@ -198,7 +198,7 @@ jobs:
     - name: Runt tests
       working-directory: /home/calyx
       run: |
-        runt -x 'cocotb' -d -o fail -j 1 --max-futures 5
+        runt -x 'cocotb|profiler' -d -o fail -j 1 --max-futures 5
 
     - name: Run Python Tests
       working-directory: /home/calyx

.gitignore

@@ -55,9 +55,8 @@ results.xml
 # btor2i ignore
 tools/btor2/btor2i/build/
 
-# vcd-parsing tmp files ignore
-tools/profiler/tmp/
-tools/profiler/logs
+# profiling ignore
+tools/profiler/data
 
 temp/
 
@@ -67,3 +66,6 @@ frontends/queues/tests/**/*.expect
 
 # for running a venv
 .venv
+
+# emacs
+*~

Dockerfile

@@ -20,6 +20,8 @@ ENV PATH="/opt/venv/bin:$PATH"
 RUN python3 -m pip install numpy==1.26.4 flit prettytable wheel hypothesis pytest simplejson cocotb==1.6.2
 # Current cocotb-bus has a bug that is fixed in more up to date repo
 RUN python3 -m pip install git+https://github.com/cocotb/cocotb-bus.git cocotbext-axi
+# Vcdvcd for profiling
+RUN python3 -m pip install vcdvcd
 
 # Install clang
 RUN apt-get install -y clang

runt.toml

@@ -686,3 +686,11 @@ make --silent -B TEST_PATH={} COCOTB_LOG_LEVEL=CRITICAL |\
   rm -f results.xml
 
 """
+
+### Profiler tests
+[[tests]]
+name = "profiler"
+paths = ["tests/profiler/*.futil"]
+cmd = """
+bash tools/profiler/get-profile-counts-info.sh {} {}.data STDOUT -d
+"""

tests/profiler/par.expect

@@ -0,0 +1,66 @@
+[get-profile-counts-info.sh] Obtaining FSM info from TDCC
+[get-profile-counts-info.sh] Obtaining cell information from component-cells backend
+[get-profile-counts-info.sh] Obtaining VCD file via simulation
+[get-profile-counts-info.sh] Using FSM info and VCD file to obtain cycle level counts
+Total clock cycles: 3
+=====SUMMARY=====
+
+Group TOP.toplevel.main.par0 Summary:
+	Total cycles: 3
+	# of times active: 1
+	Avg runtime: 3.0
+
+Group TOP.toplevel.main.wr_a Summary:
+	Total cycles: 1
+	# of times active: 1
+	Avg runtime: 1.0
+
+Group TOP.toplevel.main.wr_b Summary:
+	Total cycles: 1
+	# of times active: 1
+	Avg runtime: 1.0
+
+Group TOP.toplevel.main.wr_c Summary:
+	Total cycles: 1
+	# of times active: 1
+	Avg runtime: 1.0
+
+=====DUMP=====
+
+Group TOP.toplevel.main.par0:
+	FSM name: TOP.toplevel.main.fsm
+	FSM state ids: [0]
+	Total cycles: 3
+	# of times active: 1
+	Segments: [0, 3)
+
+Group TOP.toplevel.main.wr_a:
+	FSM name: None
+	FSM state ids: None
+	Total cycles: 1
+	# of times active: 1
+	Segments: [0, 1)
+
+Group TOP.toplevel.main.wr_b:
+	FSM name: None
+	FSM state ids: None
+	Total cycles: 1
+	# of times active: 1
+	Segments: [0, 1)
+
+Group TOP.toplevel.main.wr_c:
+	FSM name: None
+	FSM state ids: None
+	Total cycles: 1
+	# of times active: 1
+	Segments: [0, 1)
+
+Writing dump JSON to /home/ayaka/projects/calyx/tools/profiler/data//tmp/dump.json
+Writing summary to STDOUT
+name,total-cycles,times-active,avg
+TOP.toplevel.main.par0,3,1,3.0
+TOP.toplevel.main.wr_a,1,1,1.0
+TOP.toplevel.main.wr_b,1,1,1.0
+TOP.toplevel.main.wr_c,1,1,1.0
+TOTAL,3,-,-
+[get-profile-counts-info.sh] Writing visualization to /home/ayaka/projects/calyx/tools/profiler/data//tmp/visual.json

tests/profiler/par.futil

@@ -0,0 +1,41 @@
+import "primitives/core.futil";
+import "primitives/memories/comb.futil";
+
+component main() -> () {
+  cells {
+    @external(1) a = comb_mem_d1(32, 1, 1);
+    @external(1) b = comb_mem_d1(32, 1, 1);
+    @external(1) c = comb_mem_d1(32, 1, 1);
+  }
+
+  wires {
+    group wr_a {
+      a.addr0 = 1'b0;
+      a.write_en = 1'b1;
+      a.write_data = 32'd1;
+      wr_a[done] = a.done;
+    }
+
+    group wr_b {
+      b.addr0 = 1'b0;
+      b.write_en = 1'b1;
+      b.write_data = 32'd1;
+      wr_b[done] = b.done;
+    }
+
+    group wr_c {
+      c.addr0 = 1'b0;
+      c.write_en = 1'b1;
+      c.write_data = 32'd1;
+      wr_c[done] = c.done;
+    }
+  }
+
+  control {
+    par {
+      wr_a;
+      wr_b;
+      wr_c;
+    }
+  }
+}

tests/profiler/par.futil.data

@@ -0,0 +1,32 @@
+{
+  "a": {
+    "data": [
+      0
+    ],
+    "format": {
+      "numeric_type": "bitnum",
+      "is_signed": true,
+      "width": 32
+    }
+  },
+  "b": {
+    "data": [
+      0
+    ],
+    "format": {
+      "numeric_type": "bitnum",
+      "is_signed": false,
+      "width": 32
+    }
+  },
+  "c": {
+    "data": [
+      0
+    ],
+    "format": {
+      "numeric_type": "bitnum",
+      "is_signed": false,
+      "width": 32
+    }
+  }
+}

tests/profiler/simple-par.expect

@@ -0,0 +1,40 @@
+[get-profile-counts-info.sh] Obtaining FSM info from TDCC
+[get-profile-counts-info.sh] Obtaining cell information from component-cells backend
+[get-profile-counts-info.sh] Obtaining VCD file via simulation
+[get-profile-counts-info.sh] Using FSM info and VCD file to obtain cycle level counts
+Total clock cycles: 3
+=====SUMMARY=====
+
+Group TOP.toplevel.main.par0 Summary:
+	Total cycles: 3
+	# of times active: 1
+	Avg runtime: 3.0
+
+Group TOP.toplevel.main.write Summary:
+	Total cycles: 1
+	# of times active: 1
+	Avg runtime: 1.0
+
+=====DUMP=====
+
+Group TOP.toplevel.main.par0:
+	FSM name: TOP.toplevel.main.fsm
+	FSM state ids: [0]
+	Total cycles: 3
+	# of times active: 1
+	Segments: [0, 3)
+
+Group TOP.toplevel.main.write:
+	FSM name: None
+	FSM state ids: None
+	Total cycles: 1
+	# of times active: 1
+	Segments: [0, 1)
+
+Writing dump JSON to /home/ayaka/projects/calyx/tools/profiler/data//tmp/dump.json
+Writing summary to STDOUT
+name,total-cycles,times-active,avg
+TOP.toplevel.main.par0,3,1,3.0
+TOP.toplevel.main.write,1,1,1.0
+TOTAL,3,-,-
+[get-profile-counts-info.sh] Writing visualization to /home/ayaka/projects/calyx/tools/profiler/data//tmp/visual.json

tests/profiler/simple-par.futil

@@ -0,0 +1,23 @@
+import "primitives/core.futil";
+import "primitives/memories/comb.futil";
+
+component main() -> () {
+  cells {
+    @external(1) a = comb_mem_d1(32, 1, 1);
+  }
+
+  wires {
+    group write {
+      a.addr0 = 1'b0;
+      a.write_en = 1'b1;
+      a.write_data = 32'd1;
+      write[done] = a.done;
+    }
+  }
+
+  control {
+    par {
+      write;
+    }
+  }
+}

tests/profiler/simple-par.futil.data

@@ -0,0 +1,12 @@
+{
+  "a": {
+    "data": [
+      0
+    ],
+    "format": {
+      "numeric_type": "bitnum",
+      "is_signed": true,
+      "width": 32
+    }
+  }
+}

tests/profiler/simple-seq.expect

@@ -0,0 +1,27 @@
+[get-profile-counts-info.sh] Obtaining FSM info from TDCC
+[get-profile-counts-info.sh] Obtaining cell information from component-cells backend
+[get-profile-counts-info.sh] Obtaining VCD file via simulation
+[get-profile-counts-info.sh] Using FSM info and VCD file to obtain cycle level counts
+Total clock cycles: 2
+=====SUMMARY=====
+
+Group TOP.toplevel.main.write Summary:
+	Total cycles: 2
+	# of times active: 1
+	Avg runtime: 2.0
+
+=====DUMP=====
+
+Group TOP.toplevel.main.write:
+	FSM name: TOP.toplevel.main.fsm
+	FSM state ids: [0]
+	Total cycles: 2
+	# of times active: 1
+	Segments: [0, 2)
+
+Writing dump JSON to /home/ayaka/projects/calyx/tools/profiler/data//tmp/dump.json
+Writing summary to STDOUT
+name,total-cycles,times-active,avg
+TOP.toplevel.main.write,2,1,2.0
+TOTAL,2,-,-
+[get-profile-counts-info.sh] Writing visualization to /home/ayaka/projects/calyx/tools/profiler/data//tmp/visual.json

tests/profiler/simple-seq.futil

@@ -0,0 +1,23 @@
+import "primitives/core.futil";
+import "primitives/memories/comb.futil";
+
+component main() -> () {
+  cells {
+    @external(1) a = comb_mem_d1(32, 1, 1);
+  }
+
+  wires {
+    group write {
+      a.addr0 = 1'b0;
+      a.write_en = 1'b1;
+      a.write_data = 32'd1;
+      write[done] = a.done;
+    }
+  }
+
+  control {
+    seq {
+      write;
+    }
+  }
+}

tests/profiler/simple-seq.futil.data

@@ -0,0 +1,12 @@
+{
+  "a": {
+    "data": [
+      0
+    ],
+    "format": {
+      "numeric_type": "bitnum",
+      "is_signed": true,
+      "width": 32
+    }
+  }
+}

tests/profiler/while-never-true.futil

@@ -0,0 +1,46 @@
+import "primitives/core.futil";
+import "primitives/memories/comb.futil";
+
+component main() -> () {
+  cells {
+    @external(1) i = comb_mem_d1(32, 1, 1);
+    lt = std_lt(32);
+    lt_reg = std_reg(1);
+    add = std_add(32);
+  }
+
+  wires {
+    group cond {
+      i.addr0 = 1'd0;
+      lt.left = i.read_data;
+      lt.right = 32'd0;
+      lt_reg.in = lt.out;
+      lt_reg.write_en = 1'b1;
+      cond[done] = lt_reg.done;
+    }
+
+    group incr {
+      add.right = i.read_data;
+      add.left = 32'd1;
+
+      i.write_data = add.out;
+      i.addr0 = 1'd0;
+      i.write_en = 1'b1;
+
+      incr[done] = i.done;
+    }
+  }
+
+  control {
+    seq {
+      cond;
+      while lt_reg.out {
+        seq {
+          incr;
+          incr;
+          cond;
+        }
+      }
+    }
+  }
+}

tests/profiler/while-never-true.futil.data

@@ -0,0 +1,10 @@
+{
+  "i": {
+    "data": [0],
+    "format": {
+      "numeric_type": "bitnum",
+      "is_signed": false,
+      "width": 32
+    }
+  }
+}