[Profiling] Use TDCC group's go to infer first state's start time (#…

…2121)

This PR contains small revisions to profiling:
1. We now show a summary for each group before showing the complete
information.
2. We now use the corresponding TDCC group's `go` signal in order to
infer when the FSM is technically "starting".

To describe a bit more about (2) - I previously had a bug where `read`
from `language-tutorial-iterate.futil` was "active" for ~60 cycles (when
it should only be active for 16). This was because `read` corresponds to
the 0th state of the FSM of the par arm containing `read`, `write`, and
`upd`, and the 0th state corresponds to both the first group and a reset
state. To fix this, I used the `go` signal for the TDCC group that
manages the FSM to figure out when the first group is active.

tools/profiler/parse-vcd.py

@@ -7,37 +7,66 @@ def remove_size_from_name(name: str) -> str:
     return name.split('[')[0]
 
 class ProfilingInfo:
-    def __init__(self, name, fsm_name=None, fsm_value=None):
+    def __init__(self, name, fsm_name=None, fsm_values=None, tdcc_group_name=None):
         self.name = name
         self.fsm_name = fsm_name
-        self.fsm_value = fsm_value
+        self.fsm_values = fsm_values
         self.total_cycles = 0
-        self.segments = [] # Segments will be (start_time, end_time)
+        self.closed_segments = [] # Segments will be (start_time, end_time)
+        self.current_segment = None
+        self.tdcc_group = tdcc_group_name
 
     def __repr__ (self):
-        # Remove any non-closed segments
-        segment_repr = []
-        for segment in self.segments:
-            if segment["end"] != -1:
-                segment_repr.append(segment)
-        return str({"group-name" : self.name, "fsm-name": self.fsm_name, "group-fsm-value": self.fsm_value, "total-cycles": self.total_cycles, "segments": segment_repr})
+        return (f"Group {self.name}:\n" +
+        f"\tFSM name: {self.fsm_name}\n" +
+        f"\tFSM state ids: {self.fsm_values}\n" +
+        f"\tTotal cycles: {self.total_cycles}\n" +   
+        f"\tSegments: {self.closed_segments}\n"
+        )
+
+    def is_active(self):
+        return self.current_segment is not None
+
+    def start_clock_cycle(self):
+        if self.current_segment is None:
+            return -1
+        else:
+            return self.current_segment["start"]
+
+    def summary(self):
+        if len(self.closed_segments) == 0:
+            average_cycles = 0
+        else:
+            average_cycles = self.total_cycles / len(self.closed_segments)
+        return (f"Group {self.name} Summary:\n" +
+        f"\tTotal cycles: {self.total_cycles}\n" +
+        f"\t# of times active: {len(self.closed_segments)}\n" +
+        f"\tAvg runtime: {average_cycles}\n"
+        )
 
     def start_new_segment(self, curr_clock_cycle):
-        self.segments.append({"start": curr_clock_cycle, "end": -1})
+        if self.current_segment is None:
+            self.current_segment = {"start": curr_clock_cycle, "end": -1}
+        else:
+            print(f"Error! The group {self.name} is starting a new segment while the current segment is not closed.")
+            print(f"Current segment: {self.current_segment}")
+            sys.exit(1)
 
     def end_current_segment(self, curr_clock_cycle):
-        if len(self.segments) > 0:
-            # Close out previous segment by setting the end time to the current cycle            
-            if (self.segments[-1]["end"] == -1): # ignore cases where done is high forever
-                self.segments[-1]["end"] = curr_clock_cycle
-                self.total_cycles += curr_clock_cycle - self.segments[-1]["start"]
+        if self.current_segment is not None and self.current_segment["end"] == -1: # ignore cases where done is high forever
+            self.current_segment["end"] = curr_clock_cycle
+            self.closed_segments.append(self.current_segment)
+            self.total_cycles += curr_clock_cycle - self.current_segment["start"]
+            self.current_segment = None # Reset current segment    
 
 class VCDConverter(vcdvcd.StreamParserCallbacks):
 
-    def __init__(self, fsms, single_enable_names, groups_to_fsms):
+    def __init__(self, fsms, single_enable_names, tdcc_group_names, groups_to_fsms):
         super().__init__()
         self.fsms = fsms
         self.single_enable_names = single_enable_names
+        self.tdcc_group_to_values = {tdcc_group_name : [] for tdcc_group_name in tdcc_group_names}
+        self.tdcc_group_to_go_id = {tdcc_group_name : None for tdcc_group_name in tdcc_group_names}
         self.profiling_info = {}
         self.signal_to_signal_id = {fsm : None for fsm in fsms}
         self.signal_to_curr_value = {fsm : 0 for fsm in fsms}
@@ -47,8 +76,7 @@ def __init__(self, fsms, single_enable_names, groups_to_fsms):
         self.clock_id = None
         self.clock_cycle_acc = -1 # The 0th clock cycle will be 0.
         for group in groups_to_fsms:
-            fsm_name, fsm_value = groups_to_fsms[group]
-            self.profiling_info[group] = ProfilingInfo(group, fsm_name, fsm_value)
+            self.profiling_info[group] = ProfilingInfo(group, groups_to_fsms[group]["fsm"], groups_to_fsms[group]["ids"], groups_to_fsms[group]["tdcc-group-name"])
         for single_enable_group in single_enable_names:
             self.profiling_info[single_enable_group] = ProfilingInfo(single_enable_group)
             self.signal_to_curr_value[f"{single_enable_group}_go"] = -1
@@ -72,6 +100,9 @@ def enddefinitions(self, vcd, signals, cur_sig_vals):
 
         for name, id in refs:
             # We may want to optimize these nested for loops
+            for tdcc_group in self.tdcc_group_to_go_id:
+                if f"{tdcc_group}_go.out[" in name:
+                    self.tdcc_group_to_go_id[tdcc_group] = id
             for fsm in self.fsms:
                 if f"{fsm}.out[" in name:
                     self.signal_to_signal_id[fsm] = id
@@ -98,41 +129,43 @@ def value(
         # detect rising edge on clock
         if identifier_code == self.clock_id and value == "1":
             self.clock_cycle_acc += 1
+            # Update TDCC group signals first
+            for (tdcc_group_name, tdcc_signal_id) in self.tdcc_group_to_go_id.items():
+                self.tdcc_group_to_values[tdcc_group_name].append(int(cur_sig_vals[tdcc_signal_id], 2))
             # for each signal that we want to check, we need to sample the values
             for (signal_name, signal_id) in self.signal_to_signal_id.items():
                 signal_new_value = int(cur_sig_vals[signal_id], 2) # signal value at this point in time
                 fsm_curr_value = self.signal_to_curr_value[signal_name]
-                # skip values that have not changed, except for when main[go] just got activated
-                if not(self.main_go_on_time == time) and signal_new_value == fsm_curr_value:
-                    continue
                 if "_go" in signal_name and signal_new_value == 1:
                     # start of single enable group
                     group = "_".join(signal_name.split("_")[0:-1])
-                    self.profiling_info[group].start_new_segment(self.clock_cycle_acc)
+                    curr_group_info = self.profiling_info[group]
+                    # We want to start a segment regardless of whether it changed
+                    if self.main_go_on_time == time or signal_new_value != fsm_curr_value:
+                        curr_group_info.start_new_segment(self.clock_cycle_acc)
                 elif "_done" in signal_name and signal_new_value == 1:
                     # end of single enable group
                     group = "_".join(signal_name.split("_")[0:-1])
                     self.profiling_info[group].end_current_segment(self.clock_cycle_acc)
                 elif "fsm" in signal_name:
-                    # Sample FSM values
-                    if fsm_curr_value != -1:
-                        # end the previous group if there was one
+                    next_group = self.fsms[signal_name][signal_new_value]
+                    tdcc_group_values = self.tdcc_group_to_values[self.profiling_info[next_group].tdcc_group]
+                    # if the FSM value changed, then we must end the previous group (regardless of whether we can start the next group)
+                    if signal_new_value != fsm_curr_value and fsm_curr_value != -1:
                         prev_group = self.fsms[signal_name][fsm_curr_value]
                         self.profiling_info[prev_group].end_current_segment(self.clock_cycle_acc)
-                    if signal_new_value in self.fsms[signal_name]: # END should be ignored
-                        next_group = self.fsms[signal_name][signal_new_value]
-                        # start a new segment for the next group
-                        # FIXME: need to fix this for par blocks
+                    # if the FSM value didn't change but the TDCC group just got enabled, then we must start the next group
+                    if signal_new_value == fsm_curr_value and (tdcc_group_values[-1] == 1 and (len(tdcc_group_values) == 1 or tdcc_group_values[-2] == 0)):
+                        self.profiling_info[next_group].start_new_segment(self.clock_cycle_acc)
+                    if tdcc_group_values[-1] == 1 and signal_new_value != fsm_curr_value:
                         self.profiling_info[next_group].start_new_segment(self.clock_cycle_acc)
-                    else:
-                        # The state id was not in the JSON entry for this FSM. Most likely the value was the last FSM state.
-                        print(f"FSM value ignored: {signal_new_value}")
                 # Update internal signal value
-                self.signal_to_curr_value[signal_name] = signal_new_value
+                self.signal_to_curr_value[signal_name] = signal_new_value                
 
 def remap_tdcc_json(json_file):
     profiling_infos = json.load(open(json_file))
     single_enable_names = set()
+    tdcc_group_names = set()
     groups_to_fsms = {}
     fsms = {} # Remapping of JSON data for easy access
     for profiling_info in profiling_infos:
@@ -142,20 +175,30 @@ def remap_tdcc_json(json_file):
             fsms[fsm_name] = {}
             for state in fsm["states"]:
                 fsms[fsm_name][state["id"]] = state["group"]
-                groups_to_fsms[state["group"]] = (fsm_name, state["id"])
+                group_name = state["group"]
+                if group_name not in groups_to_fsms:
+                    groups_to_fsms[group_name] = {"fsm": fsm_name, "tdcc-group-name": fsm["group"], "ids": [state["id"]]}
+                    tdcc_group_names.add(fsm["group"]) # Hack: Keep track of the TDCC group for use later
+                else:     
+                    groups_to_fsms[group_name]["ids"].append(state["id"])  
         else:
-            group_name = profiling_info["SingleEnable"]["group"]
-            single_enable_names.add(group_name)
+            single_enable_names.add(profiling_info["SingleEnable"]["group"])
 
-    return fsms, single_enable_names, groups_to_fsms
+    return fsms, single_enable_names, tdcc_group_names, groups_to_fsms
 
 
 def main(vcd_filename, json_file):
-    fsms, single_enable_names, groups_to_fsms = remap_tdcc_json(json_file)
-    converter = VCDConverter(fsms, single_enable_names, groups_to_fsms)
+    fsms, single_enable_names, tdcc_group_names, groups_to_fsms = remap_tdcc_json(json_file)
+    converter = VCDConverter(fsms, single_enable_names, tdcc_group_names, groups_to_fsms)
     vcdvcd.VCDVCD(vcd_filename, callbacks=converter, store_tvs=False)
     print(f"Total clock cycles: {converter.clock_cycle_acc}")
-    for group_info in converter.profiling_info.values():
+    print("=====SUMMARY=====")
+    print()
+    for group_info in filter(lambda group : not group.name.startswith("tdcc") and not group.name.endswith("END"), converter.profiling_info.values()):
+        print(group_info.summary())
+    print("=====DUMP=====")
+    print()
+    for group_info in filter(lambda group : not group.name.startswith("tdcc") and not group.name.endswith("END"), converter.profiling_info.values()):
         print(group_info)
 
 if __name__ == "__main__":