feat(processing_time_visualizer): add summarize option #90

a-maumau · 2024-08-05T02:06:25Z

Description

This PR will add a summarized output option for processing_time_visualizer.

In some packages, the visualized information might get too long for investigation.
For profiling purposes, it may be better to have an option for visualizing the total processing time and the total number of times it is called.

Use --summarize for testing it.

sample output

Without the summarize option:

output

objectsCallback: 17.99 [ms]
    ├── removeStaleTrafficLightInfo: 0.00 [ms]
    ├── updateObjectData: 0.00 [ms]
    ├── getCurrentLanelets: 0.27 [ms]
    │   ├── checkCloseLaneletCondition: 0.06 [ms]
    │   ├── isDuplicated: 0.00 [ms]
    │   ├── calculateLocalLikelihood: 0.03 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   └── checkCloseLaneletCondition: 0.01 [ms]
    ├── updateRoadUsersHistory: 0.03 [ms]
    ├── updateObjectData: 0.00 [ms]
    ├── getCurrentLanelets: 0.40 [ms]
    │   ├── checkCloseLaneletCondition: 0.09 [ms]
    │   ├── isDuplicated: 0.00 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   └── calculateLocalLikelihood: 0.08 [ms]
    ├── updateRoadUsersHistory: 0.02 [ms]
    ├── updateObjectData: 0.00 [ms]
    ├── getCurrentLanelets: 0.24 [ms]
    │   ├── checkCloseLaneletCondition: 0.04 [ms]
    │   ├── isDuplicated: 0.00 [ms]
    │   ├── calculateLocalLikelihood: 0.03 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   └── checkCloseLaneletCondition: 0.01 [ms]
    ├── updateRoadUsersHistory: 0.02 [ms]
    ├── updateObjectData: 0.00 [ms]
    ├── getCurrentLanelets: 0.31 [ms]
    │   ├── checkCloseLaneletCondition: 0.08 [ms]
    │   ├── isDuplicated: 0.00 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   └── calculateLocalLikelihood: 0.07 [ms]
    ├── updateRoadUsersHistory: 0.02 [ms]
    ├── updateObjectData: 0.00 [ms]
    ├── getCurrentLanelets: 0.43 [ms]
    │   ├── checkCloseLaneletCondition: 0.08 [ms]
    │   ├── isDuplicated: 0.00 [ms]
    │   ├── calculateLocalLikelihood: 0.07 [ms]
    │   ├── checkCloseLaneletCondition: 0.07 [ms]
    │   ├── isDuplicated: 0.00 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   └── checkCloseLaneletCondition: 0.01 [ms]
    ├── updateRoadUsersHistory: 0.02 [ms]
    ├── getPredictedReferencePath: 1.03 [ms]
    │   ├── predictObjectManeuver: 0.09 [ms]
    │   │   └── predictObjectManeuverByLatDiffDistance: 0.07 [ms]
    │   ├── calculateManeuverProbability: 0.00 [ms]
    │   ├── addReferencePaths: 0.47 [ms]
    │   │   ├── updateFuturePossibleLanelets: 0.01 [ms]
    │   │   └── convertPathType: 0.44 [ms]
    │   ├── addReferencePaths: 0.00 [ms]
    │   └── addReferencePaths: 0.41 [ms]
    │       ├── updateFuturePossibleLanelets: 0.01 [ms]
    │       └── convertPathType: 0.38 [ms]
    ├── updateObjectData: 0.00 [ms]
    ├── getCurrentLanelets: 0.39 [ms]
    │   ├── checkCloseLaneletCondition: 0.09 [ms]
    │   ├── isDuplicated: 0.00 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   └── calculateLocalLikelihood: 0.07 [ms]
    ├── updateRoadUsersHistory: 0.03 [ms]
    ├── updateObjectData: 0.00 [ms]
    ├── getCurrentLanelets: 0.39 [ms]
    │   ├── checkCloseLaneletCondition: 0.07 [ms]
    │   ├── isDuplicated: 0.00 [ms]
    │   ├── calculateLocalLikelihood: 0.06 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.04 [ms]
    │   ├── checkCloseLaneletCondition: 0.04 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   └── checkCloseLaneletCondition: 0.01 [ms]
    ├── updateRoadUsersHistory: 0.02 [ms]
    ├── getPredictedReferencePath: 1.28 [ms]
    │   ├── predictObjectManeuver: 0.11 [ms]
    │   │   └── predictObjectManeuverByLatDiffDistance: 0.10 [ms]
    │   │       ├── calcRightLateralOffset: 0.01 [ms]
    │   │       ├── calcRightLateralOffset: 0.00 [ms]
    │   │       ├── calcRightLateralOffset: 0.00 [ms]
    │   │       └── calcRightLateralOffset: 0.00 [ms]
    │   ├── calculateManeuverProbability: 0.00 [ms]
    │   ├── addReferencePaths: 0.00 [ms]
    │   ├── addReferencePaths: 0.00 [ms]
    │   └── addReferencePaths: 1.08 [ms]
    │       ├── updateFuturePossibleLanelets: 0.01 [ms]
    │       └── convertPathType: 0.96 [ms]
    ├── updateObjectData: 0.00 [ms]
    ├── getCurrentLanelets: 0.33 [ms]
    │   ├── checkCloseLaneletCondition: 0.10 [ms]
    │   ├── isDuplicated: 0.00 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   └── calculateLocalLikelihood: 0.08 [ms]
    ├── updateRoadUsersHistory: 0.03 [ms]
    ├── updateObjectData: 0.00 [ms]
    ├── getCurrentLanelets: 0.31 [ms]
    │   ├── checkCloseLaneletCondition: 0.04 [ms]
    │   ├── isDuplicated: 0.00 [ms]
    │   ├── calculateLocalLikelihood: 0.03 [ms]
    │   ├── checkCloseLaneletCondition: 0.03 [ms]
    │   ├── isDuplicated: 0.00 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.03 [ms]
    │   └── checkCloseLaneletCondition: 0.03 [ms]
    ├── updateRoadUsersHistory: 0.02 [ms]
    ├── getPredictedReferencePath: 1.69 [ms]
    │   ├── predictObjectManeuver: 0.08 [ms]
    │   │   └── predictObjectManeuverByLatDiffDistance: 0.07 [ms]
    │   │       ├── calcRightLateralOffset: 0.00 [ms]
    │   │       ├── calcRightLateralOffset: 0.00 [ms]
    │   │       ├── calcRightLateralOffset: 0.00 [ms]
    │   │       └── calcRightLateralOffset: 0.00 [ms]
    │   ├── calculateManeuverProbability: 0.00 [ms]
    │   ├── addReferencePaths: 1.14 [ms]
    │   │   ├── updateFuturePossibleLanelets: 0.01 [ms]
    │   │   └── convertPathType: 1.07 [ms]
    │   ├── addReferencePaths: 0.00 [ms]
    │   └── addReferencePaths: 0.36 [ms]
    │       ├── updateFuturePossibleLanelets: 0.02 [ms]
    │       └── convertPathType: 0.33 [ms]
    ├── updateObjectData: 0.00 [ms]
    ├── getCurrentLanelets: 0.34 [ms]
    │   ├── checkCloseLaneletCondition: 0.10 [ms]
    │   ├── isDuplicated: 0.00 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   └── calculateLocalLikelihood: 0.07 [ms]
    ├── updateRoadUsersHistory: 0.03 [ms]
    ├── updateObjectData: 0.00 [ms]
    ├── getCurrentLanelets: 0.37 [ms]
    │   ├── checkCloseLaneletCondition: 0.02 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.04 [ms]
    │   ├── isDuplicated: 0.00 [ms]
    │   ├── calculateLocalLikelihood: 0.04 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.07 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   └── checkCloseLaneletCondition: 0.01 [ms]
    ├── updateRoadUsersHistory: 0.03 [ms]
    ├── getPredictedReferencePath: 0.62 [ms]
    │   ├── predictObjectManeuver: 0.10 [ms]
    │   │   └── predictObjectManeuverByLatDiffDistance: 0.08 [ms]
    │   │       ├── calcRightLateralOffset: 0.00 [ms]
    │   │       ├── calcRightLateralOffset: 0.00 [ms]
    │   │       ├── calcRightLateralOffset: 0.00 [ms]
    │   │       └── calcRightLateralOffset: 0.00 [ms]
    │   ├── calculateManeuverProbability: 0.00 [ms]
    │   ├── addReferencePaths: 0.00 [ms]
    │   ├── addReferencePaths: 0.00 [ms]
    │   └── addReferencePaths: 0.47 [ms]
    │       ├── updateFuturePossibleLanelets: 0.01 [ms]
    │       └── convertPathType: 0.44 [ms]
    ├── updateObjectData: 0.00 [ms]
    ├── getCurrentLanelets: 0.55 [ms]
    │   ├── checkCloseLaneletCondition: 0.07 [ms]
    │   ├── checkCloseLaneletCondition: 0.04 [ms]
    │   ├── checkCloseLaneletCondition: 0.04 [ms]
    │   ├── checkCloseLaneletCondition: 0.02 [ms]
    │   ├── checkCloseLaneletCondition: 0.07 [ms]
    │   ├── checkCloseLaneletCondition: 0.03 [ms]
    │   ├── checkCloseLaneletCondition: 0.04 [ms]
    │   ├── checkCloseLaneletCondition: 0.03 [ms]
    │   ├── checkCloseLaneletCondition: 0.02 [ms]
    │   └── checkCloseLaneletCondition: 0.03 [ms]
    ├── updateRoadUsersHistory: 0.02 [ms]
    ├── updateObjectData: 0.00 [ms]
    ├── getCurrentLanelets: 0.47 [ms]
    │   ├── checkCloseLaneletCondition: 0.04 [ms]
    │   ├── isDuplicated: 0.00 [ms]
    │   ├── calculateLocalLikelihood: 0.03 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.01 [ms]
    │   ├── checkCloseLaneletCondition: 0.07 [ms]
    │   ├── isDuplicated: 0.00 [ms]
    │   ├── checkCloseLaneletCondition: 0.04 [ms]
    │   ├── isDuplicated: 0.00 [ms]
    │   ├── checkCloseLaneletCondition: 0.07 [ms]
    │   ├── isDuplicated: 0.00 [ms]
    │   └── checkCloseLaneletCondition: 0.01 [ms]
    ├── updateRoadUsersHistory: 0.02 [ms]
    └── getPredictedReferencePath: 0.84 [ms]
        ├── predictObjectManeuver: 0.03 [ms]
        │   └── predictObjectManeuverByLatDiffDistance: 0.01 [ms]
        ├── calculateManeuverProbability: 0.00 [ms]
        ├── addReferencePaths: 0.43 [ms]
        │   ├── updateFuturePossibleLanelets: 0.01 [ms]
        │   └── convertPathType: 0.41 [ms]
        ├── addReferencePaths: 0.00 [ms]
        └── addReferencePaths: 0.30 [ms]
            ├── updateFuturePossibleLanelets: 0.01 [ms]
            └── convertPathType: 0.28 [ms]

With --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

Tests performed

Tested by checking the node names and their counts in the same tree.

Notes for reviewers

Interface changes

Effects on system behavior

Pre-review checklist for the PR author

The PR author must check the checkboxes below when creating the PR.

I've confirmed the contribution guidelines.
The PR follows the pull request guidelines.

In-review checklist for the PR reviewers

The PR reviewers must check the checkboxes below before approval.

The PR follows the pull request guidelines.
The PR has been properly tested.
The PR has been reviewed by the code owners.

Post-review checklist for the PR author

The PR author must check the checkboxes below before merging.

There are no open discussions or they are tracked via tickets.
The PR is ready for merge.

After all checkboxes are checked, anyone who has write access can merge the PR.

Signed-off-by: a-maumau <[email protected]>

technolojin

Summarized visualization is much better to analyze the overall processing time.

LGTM!

yhisaki · 2024-08-05T06:00:34Z

Thank you for the PR. I also thought this feature was necessary. I'll review it, so please wait a moment.

Signed-off-by: Y.Hisaki <[email protected]>

yhisaki · 2024-08-05T10:19:27Z

@a-maumau
I've created a PR that allows the summarize option to be changed dynamically after execution, rather than defining it before execution. In my opinion, I think this is more user-friendly, but what do you think?

In the following video, the summarize mode is toggled by pressing the 's' key.
Screencast from 08-05-2024 07:09:50 PM.webm

…essing_time_visualizer feat(processing_time_visualizer): make summarize option dynamic

a-maumau · 2024-08-06T01:06:48Z

@yhisaki Yes, I agree with that.
Thank you!
I have merged the PR in the fork repo.

a-maumau · 2024-08-06T01:11:42Z

By the way, should we add total processing time or something to the printing like: updateObjectData: total 0.03 [ms], run count: 13?

I think it may be quite obvious that it is total processing time, but for just in case.

yhisaki · 2024-08-06T01:53:39Z

In terms of improving usability, it would be better!
In addition, how about displaying the avg as follows?

func_a: total 12.71 [ms], avg 12.71 [ms], run_count: 1
    └── func_b: total 11.56 [ms], avg 3.85 [ms], run_count: 3
        ├── func_d: total 1.13 [ms], avg 1.13 [ms], run_count: 1
        └── func_c: total 6.21 [ms], avg 3.10 [ms], run_count: 2

            line += (
                f"{node.name}: total {node.processing_time:.2f} [ms], avg {node.processing_time / node.run_count:.2f} [ms], run_count: {node.run_count}"
                if summarize
                else f"{node.name}: {node.processing_time:.2f} [ms]"
            )

Signed-off-by: a-maumau <[email protected]>

…e_visualizer

a-maumau · 2024-08-06T05:31:07Z

@yhisaki I added your suggestion at 25932b2 .

yhisaki · 2024-08-06T06:09:54Z

@a-maumau
Thank you!! I approved!

a-maumau · 2024-08-06T10:11:25Z

@yhisaki
I don't have the merge privileges.
So could you merge this PR instead of me?

a-maumau added 2 commits August 5, 2024 04:19

add summarize feature

663be20

Signed-off-by: a-maumau <[email protected]>

add summarize

4e5caf1

Signed-off-by: a-maumau <[email protected]>

github-actions bot added type:documentation component:common labels Aug 5, 2024

pre-commit-ci bot and others added 2 commits August 5, 2024 02:06

style(pre-commit): autofix

2f7c8cc

fix typo

325e024

Signed-off-by: a-maumau <[email protected]>

technolojin self-assigned this Aug 5, 2024

technolojin approved these changes Aug 5, 2024

View reviewed changes

technolojin requested review from yhisaki and soblin August 5, 2024 02:45

make summarize option dynamic

5d12e09

Signed-off-by: Y.Hisaki <[email protected]>

Merge pull request #1 from yhisaki/mau/feat/autoware_debug_tools/proc…

7467df6

…essing_time_visualizer feat(processing_time_visualizer): make summarize option dynamic

a-maumau and others added 3 commits August 6, 2024 14:17

apply suggestion

25932b2

Signed-off-by: a-maumau <[email protected]>

Merge branch 'main' into mau/feat/autoware_debug_tools/processing_tim…

e2646d1

…e_visualizer

style(pre-commit): autofix

2d9721a

yhisaki approved these changes Aug 6, 2024

View reviewed changes

yhisaki added the tag:run-build-and-test-differential label Aug 6, 2024

yhisaki enabled auto-merge (squash) August 6, 2024 10:31

yhisaki merged commit d5eae1a into autowarefoundation:main Aug 6, 2024
24 checks passed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

feat(processing_time_visualizer): add summarize option #90

feat(processing_time_visualizer): add summarize option #90

a-maumau commented Aug 5, 2024 •

edited

Loading

technolojin left a comment

yhisaki commented Aug 5, 2024

yhisaki commented Aug 5, 2024

a-maumau commented Aug 6, 2024

a-maumau commented Aug 6, 2024

yhisaki commented Aug 6, 2024

a-maumau commented Aug 6, 2024 •

edited

Loading

yhisaki commented Aug 6, 2024

a-maumau commented Aug 6, 2024

feat(processing_time_visualizer): add summarize option #90

feat(processing_time_visualizer): add summarize option #90

Conversation

a-maumau commented Aug 5, 2024 • edited Loading

Description

sample output

Related links

Tests performed

Notes for reviewers

Interface changes

Effects on system behavior

Pre-review checklist for the PR author

In-review checklist for the PR reviewers

Post-review checklist for the PR author

technolojin left a comment

Choose a reason for hiding this comment

yhisaki commented Aug 5, 2024

yhisaki commented Aug 5, 2024

a-maumau commented Aug 6, 2024

a-maumau commented Aug 6, 2024

yhisaki commented Aug 6, 2024

a-maumau commented Aug 6, 2024 • edited Loading

yhisaki commented Aug 6, 2024

a-maumau commented Aug 6, 2024

a-maumau commented Aug 5, 2024 •

edited

Loading

a-maumau commented Aug 6, 2024 •

edited

Loading