feat(processing_time_visualizer): add summarize option (#90)

* add summarize feature Signed-off-by: a-maumau <[email protected]> * add summarize Signed-off-by: a-maumau <[email protected]> * style(pre-commit): autofix * fix typo Signed-off-by: a-maumau <[email protected]> * make summarize option dynamic Signed-off-by: Y.Hisaki <[email protected]> * apply suggestion Signed-off-by: a-maumau <[email protected]> * style(pre-commit): autofix --------- Signed-off-by: a-maumau <[email protected]> Signed-off-by: Y.Hisaki <[email protected]> Co-authored-by: pre-commit-ci[bot] <66853113+pre-commit-ci[bot]@users.noreply.github.com> Co-authored-by: Y.Hisaki <[email protected]>
autowarefoundation · Aug 6, 2024 · d5eae1a · d5eae1a
1 parent a53a926
commit d5eae1a
Show file tree

Hide file tree

Showing 4 changed files with 126 additions and 19 deletions.
diff --git a/common/autoware_debug_tools/README.md b/common/autoware_debug_tools/README.md
@@ -22,6 +22,32 @@ This tool visualizes `tier4_debug_msgs/msg/ProcessingTimeTree` messages.
 
    ![visualize-tree](images/visualize-tree.png)
 
+#### summarized output
+
+Running with `--summarize`, it will output the summarized information.
+
+```Text
+> ros2 run autoware_debug_tools processing_time_visualizer --summarize
+
+objectsCallback: 17.99 [ms], run count: 1
+    ├── removeStaleTrafficLightInfo: 0.00 [ms], run count: 1
+    ├── updateObjectData: 0.03 [ms], run count: 13
+    ├── getCurrentLanelets: 4.81 [ms], run count: 13
+    │   ├── checkCloseLaneletCondition: 2.43 [ms], run count: 130
+    │   ├── isDuplicated: 0.02 [ms], run count: 17
+    │   └── calculateLocalLikelihood: 0.66 [ms], run count: 12
+    ├── updateRoadUsersHistory: 0.30 [ms], run count: 13
+    └── getPredictedReferencePath: 5.47 [ms], run count: 5
+        ├── predictObjectManeuver: 0.40 [ms], run count: 5
+        │   └── predictObjectManeuverByLatDiffDistance: 0.34 [ms], run count: 5
+        │       └── calcRightLateralOffset: 0.03 [ms], run count: 12
+        ├── calculateManeuverProbability: 0.01 [ms], run count: 5
+        └── addReferencePaths: 4.66 [ms], run count: 15
+            ├── updateFuturePossibleLanelets: 0.08 [ms], run count: 8
+            └── convertPathType: 4.29 [ms], run count: 8
+
+```
+
 ## System Usage Monitor
 
 The purpose of the System Usage Monitor is to monitor, visualize and publish the CPU usage and memory usage of the ROS processes. By providing a real-time terminal-based visualization, users can easily confirm the cpu and memory usage as in the picture below.

diff --git a/common/autoware_debug_tools/autoware_debug_tools/processing_time_visualizer/node.py b/common/autoware_debug_tools/autoware_debug_tools/processing_time_visualizer/node.py
@@ -26,6 +26,7 @@ def __init__(self):
         self.worst_case_tree: Dict[str, ProcessingTimeTree] = {}
         self.stdcscr = init_curses()
         self.show_comment = False
+        self.summarize_output = False
         print_trees("🌲 Processing Time Tree 🌲", self.topic_name, self.trees, self.stdcscr)
 
         self.create_timer(0.1, self.update_screen)
@@ -65,12 +66,16 @@ def update_screen(self):
         key = self.stdcscr.getch()
 
         self.show_comment = not self.show_comment if key == ord("c") else self.show_comment
+        self.summarize_output = (
+            not self.summarize_output if key == ord("s") else self.summarize_output
+        )
         logs = print_trees(
             "🌲 Processing Time Tree 🌲",
             self.topic_name,
             self.trees.values(),
             self.stdcscr,
             self.show_comment,
+            self.summarize_output,
         )
         if key == ord("y"):
             pyperclip.copy(logs)
@@ -82,7 +87,7 @@ def update_screen(self):
             raise KeyboardInterrupt
 
     def callback(self, msg: ProcessingTimeTreeMsg):
-        tree = ProcessingTimeTree.from_msg(msg)
+        tree = ProcessingTimeTree.from_msg(msg, self.summarize_output)
         self.trees[tree.name] = tree
         if tree.name not in self.worst_case_tree:
             self.worst_case_tree[tree.name] = tree
@@ -112,7 +117,10 @@ def main(args=None):
             exit(1)
         print("⏰ Worst Case Execution Time ⏰")
         for tree in node.worst_case_tree.values():
-            print(tree, end=None)
+            tree_str = "".join(
+                [line + "\n" for line in tree.to_lines(summarize=node.summarize_output)]
+            )
+            print(tree_str, end=None)
 
 
 if __name__ == "__main__":

diff --git a/common/autoware_debug_tools/autoware_debug_tools/processing_time_visualizer/print_tree.py b/common/autoware_debug_tools/autoware_debug_tools/processing_time_visualizer/print_tree.py
@@ -13,6 +13,7 @@ def print_trees(
     trees: List[ProcessingTimeTree],
     stdscr: curses.window,
     show_comment: bool = False,
+    summarize: bool = False,
 ):
     stdscr.clear()
     height, width = stdscr.getmaxyx()
@@ -21,14 +22,16 @@ def print_trees(
         : width - 2
     ]
     stdscr.addstr(1, 0, topic_showing, curses.color_pair(1))
-    tree_lines = list(chain.from_iterable(tree.to_lines(show_comment) + [""] for tree in trees))
+    tree_lines = list(
+        chain.from_iterable(tree.to_lines(show_comment, summarize) + [""] for tree in trees)
+    )
     tree_lines = wrap_lines(tree_lines, width, height - 2)
     for i, line in enumerate(tree_lines):
         stdscr.addstr(i + 2, 1, line)
     stdscr.addstr(
         height - 1,
         0,
-        "'q' => quit. 'r' => quit & output json report to clipboard. 'c' => show comment. 'y' => copy."[
+        "'q' => quit. 'r' => quit & output json report to clipboard. 'c' => show comment. 's' => summarize. 'y' => copy."[
             : width - 2
         ],
     )

diff --git a/common/autoware_debug_tools/autoware_debug_tools/processing_time_visualizer/tree.py b/common/autoware_debug_tools/autoware_debug_tools/processing_time_visualizer/tree.py
@@ -11,34 +11,96 @@ def __init__(
         comment: str = "",
         id: int = 1,  # noqa
         parent_id: int = 0,
+        run_count: int = 1,
     ):
         self.name = name
         self.processing_time = processing_time
         self.comment = comment
         self.id = id
         self.parent_id = parent_id
+        self.run_count = run_count
         self.children = []
+        # Dict of {node name: node id}
+        self.children_node_name_to_id: Dict[str, int] = {}
 
     @classmethod
-    def from_msg(cls, msg: ProcessingTimeTreeMsg) -> "ProcessingTimeTree":
-        # Create a dictionary to map node IDs to ProcessingTimeTree objects
-        node_dict: Dict[int, ProcessingTimeTree] = {
-            node.id: ProcessingTimeTree(
-                node.name, node.processing_time, node.comment, node.id, node.parent_id
-            )
-            for node in msg.nodes
-        }
+    def from_msg(cls, msg: ProcessingTimeTreeMsg, summarize: bool = False) -> "ProcessingTimeTree":
+        if summarize:
+            node_dict: Dict[int, ProcessingTimeTree] = {}
+            # Mapping for children whose parent gets merged
+            parent_alias_dict: Dict[int, int] = {}
+
+            for node in msg.nodes:
+                parent_id = node.parent_id
+                aliased_parent_id = parent_alias_dict.get(node.parent_id)
+
+                if aliased_parent_id or parent_id in node_dict:
+                    if aliased_parent_id:
+                        parent_id = aliased_parent_id
+
+                    # If node name already exist, use that node for aggregation
+                    agg_node_id = node_dict[parent_id].children_node_name_to_id.get(node.name)
+                    if agg_node_id:
+                        agg_node = node_dict[agg_node_id]
+
+                        # Create alias from current node to agg_node for its child nodes
+                        if node.id not in parent_alias_dict:
+                            parent_alias_dict[node.id] = agg_node_id
+
+                        agg_node.processing_time += node.processing_time
+                        agg_node.run_count += 1
+                    else:
+                        # If it is not in parent's children_name_to_id, it is not in node_dict
+                        node_dict[node.id] = ProcessingTimeTree(
+                            node.name, node.processing_time, node.comment, node.id, parent_id
+                        )
+
+                        node_dict[parent_id].children_node_name_to_id[node.name] = node.id
+                else:
+                    node_dict[node.id] = ProcessingTimeTree(
+                        node.name, node.processing_time, node.comment, node.id, node.parent_id
+                    )
+
+            # Build the tree structure
+            for node in list(node_dict.values()):
+                parent = node_dict.get(node.parent_id)
+                if parent is None:
+                    aliased_parent_id = parent_alias_dict.get(node.parent_id)
+                    parent = node_dict.get(aliased_parent_id)
+
+                if parent:
+                    # Checking the case child came first
+                    agg_node_id = parent.children_node_name_to_id.get(node.name)
+                    if agg_node_id:
+                        # Avoid aggregated node itself
+                        if agg_node_id != node.id:
+                            agg_node = node_dict[agg_node_id]
+                            agg_node.processing_time += node.processing_time
+                            agg_node.run_count += 1
+                    else:
+                        parent.children_node_name_to_id[node.name] = node.id
+
+                    parent.children.append(node)
+        else:
+            # Create a dictionary to map node IDs to ProcessingTimeTree objects
+            node_dict: Dict[int, ProcessingTimeTree] = {
+                node.id: ProcessingTimeTree(
+                    node.name, node.processing_time, node.comment, node.id, node.parent_id
+                )
+                for node in msg.nodes
+            }
+
+            # Build the tree structure
+            for node in list(node_dict.values()):
+                parent = node_dict.get(node.parent_id)
+                if parent:
+                    parent.children.append(node)
 
-        # Build the tree structure
         root = node_dict[1]
-        for node in list(node_dict.values()):
-            parent = node_dict.get(node.parent_id)
-            if parent:
-                parent.children.append(node)
 
         return root
 
-    def to_lines(self, show_comment: bool = True) -> str:
+    def to_lines(self, show_comment: bool = True, summarize: bool = False) -> str:
         def construct_string(
             node: "ProcessingTimeTree",
             lines: list,
@@ -50,7 +112,15 @@ def construct_string(
             line = ""
             if not is_root:
                 line += prefix + ("└── " if is_last else "├── ")
-            line += f"{node.name}: {node.processing_time:.2f} [ms]"
+            line += (
+                (
+                    f"{node.name}: total {node.processing_time:.2f} [ms], "
+                    f"avg. {node.processing_time / node.run_count:.2f} [ms], "
+                    f"run count: {node.run_count}"
+                )
+                if summarize
+                else f"{node.name}: {node.processing_time:.2f} [ms]"
+            )
             line += f": {node.comment}" if show_comment and node.comment else ""
             lines.append(line)
             # Recur for each child node