Improves timer to track mean and std #3233

AntoineRichard · 2025-08-20T12:39:01Z

Description

Improved the timer to track mean and standard deviation. Also added some options to enable or disable it, as well as display different units.

Fixes #3232

We can now toggle the timers on or off using global flags:

Timer.enable_display_output = True
Timer.enable = False

They support different typer of display units:

s for seconds
ms for milliseconds
us for microseconds
ns for nanoseconds

It supports local flags to turn it on or off:

    @Timer(name="step", msg="Step took:", enable=True, format="us")
    def step(self, action: torch.Tensor) -> VecEnvStepReturn:
        """Execute one time-step of the environment's dynamics and reset terminated environments.

        Unlike the :class:`ManagerBasedEnv.step` class, the function performs the following operations:
        """

Type of change

New feature (non-breaking change which adds functionality)

Sample output:

Pre physics step took: Last: 13.959998 us, Mean: 16.989330 us, Std: 16.355029 us, N: 97
Apply action took: Last: 57.998001 us, Mean: 70.876819 us, Std: 17.586332 us, N: 193
Newton simulation step took: Last: 2361.953000 us, Mean: 2410.160786 us, Std: 184.928652 us, N: 192
Apply action took: Last: 73.888001 us, Mean: 70.892340 us, Std: 17.542273 us, N: 194
Newton simulation step took: Last: 2274.202998 us, Mean: 2409.456342 us, Std: 184.707038 us, N: 193
Get dones took: Last: 503.935000 us, Mean: 3176.439361 us, Std: 25855.625066 us, N: 97
Get rewards took: Last: 100.394001 us, Mean: 785.672928 us, Std: 6466.543603 us, N: 97
Reset idx took: Last: 1173.642002 us, Mean: 2392.515064 us, Std: 9785.688885 us, N: 62
Get observations took: Last: 78.683999 us, Mean: 107.013663 us, Std: 201.971979 us, N: 98
Step took: Last: 20791.483003 us, Mean: 40550.339897 us, Std: 201595.174005 us, N: 97

Checklist

I have run the pre-commit checks with ./isaaclab.sh --format
I have made corresponding changes to the documentation
My changes generate no new warnings
I have added tests that prove my fix is effective or that my feature works
I have updated the changelog and the corresponding version in the extension's config/extension.toml file
I have added my name to the CONTRIBUTORS.md or my name already exists there

jtigue-bdai

Looks good, mostly NITs

jtigue-bdai · 2025-08-20T13:47:32Z

source/isaaclab/isaaclab/utils/timer.py

+    """
+
+    def update_welford(self, value: float):
+        """Update the welford's algorithm with a new value."""


please add args to docstring.

If this is a private method, please start it with "_" and move it to the end of the file.

Would be good to link to the Welford's algorithm description to make it easier for new user.

jtigue-bdai · 2025-08-20T13:48:03Z

source/isaaclab/isaaclab/utils/timer.py

+
+    @staticmethod
+    def get_timer_statistics(name: str) -> dict[str, float]:
+        """Retrieves the time logged in the global dictionary


please add args to docstring.

jtigue-bdai · 2025-08-20T13:54:27Z

source/isaaclab/isaaclab/utils/timer.py

+        # Check if the format is valid
+        assert format in ["s", "ms", "us", "ns"], f"Invalid format, {format} is not in [s, ms, us, ns]"
+        # Convert the format to a multiplier
+        self._multiplier = {


NIT:

Suggested change

self._multiplier = {

self._unit_multiplier = {

ooctipus · 2025-08-20T20:10:25Z

@AntoineRichard Thanks this seems very useful

out of curious,
how do you disable or enable the timer just from command line say running a train.py?

Mayankm96 · 2025-08-21T07:04:09Z

source/isaaclab/isaaclab/utils/timer.py

@@ -60,36 +63,68 @@ class Timer(ContextDecorator):
    Reference: https://gist.github.com/sumeet/1123871
    """

-    timing_info: ClassVar[dict[str, float]] = dict()
+    timing_info: ClassVar[dict[str, dict[str, float]]] = dict()


What is the second dict for? Can you update the docstring for it?

Mayankm96 · 2025-08-21T07:04:37Z

source/isaaclab/isaaclab/utils/timer.py

    """Dictionary for storing the elapsed time per timer instances globally.

    This dictionary logs the timer information. The keys are the names given to the timer class
    at its initialization. If no :attr:`name` is passed to the constructor, no time
    is recorded in the dictionary.
    """

-    def __init__(self, msg: str | None = None, name: str | None = None):
+    enable = True


Is this a class variable?

Suggested change

enable = True

enable: ClassVar[bool] = True

Yes, I need to rename it. I'll do a pass now to address all the comments! Thanks :)

Mayankm96 · 2025-08-21T07:06:35Z

source/isaaclab/isaaclab/utils/timer.py

        """
        self._msg = msg
        self._name = name
        self._start_time = None
        self._stop_time = None
        self._elapsed_time = None
+        self._enable = enable if Timer.enable else False


This seems a bit unintuitive. If a user sets the flag as input, I would have assumed that they want the timer to be enabled?

Also, maybe it is better to rename the global enable flag to something more dinstinctful to avoid confusion with local _enable variable.

The global flag is here to allow to toggle these off when running trainings, but toggle them on when running benchmarks. The idea is that we can have permanent probing points in the code that are only enabled when running the benchmarks. Alternatively we could create groups, and toggle on or off some specific groups. So the idea with the enable override is to allow killing the timers when we want from a global flag. But I guess an argument could be made to use a global variable as the input of these timers?

Mayankm96 · 2025-08-21T07:07:16Z

source/isaaclab/isaaclab/utils/timer.py

+        self._format = format
+
+        # Check if the format is valid
+        assert format in ["s", "ms", "us", "ns"], f"Invalid format, {format} is not in [s, ms, us, ns]"


Hm using ValueError is better than assertion error here.

Mayankm96 · 2025-08-21T07:07:56Z

source/isaaclab/isaaclab/utils/timer.py

+            "s": 1.0,
+            "ms": 1000.0,
+            "us": 1000000.0,
+            "ns": 1000000000.0,


Suggested change

"s": 1.0,

"ms": 1000.0,

"us": 1000000.0,

"ns": 1000000000.0,

"s": 1.0,

"ms": 1.0e3,

"us": 1.0e6,

"ns": 1.0e9,

Easier to follow than counting zeros ;)

Mayankm96 · 2025-08-21T07:09:21Z

source/isaaclab/isaaclab/utils/timer.py

+            }
+
+    """
+    Online welford's algorithm to compute the mean and std of the elapsed time


Suggested change

Online welford's algorithm to compute the mean and std of the elapsed time

Internal Helpers.

Mayankm96

Could you update the usage of the class in the docstrings to use these new features? Otherwise they get burried :)

Also now, is it going over per-line of code to get statistics or you had other timers as well in the codebase to log?

Pre physics step took: Last: 13.959998 us, Mean: 16.989330 us, Std: 16.355029 us, N: 97
Apply action took: Last: 57.998001 us, Mean: 70.876819 us, Std: 17.586332 us, N: 193
Newton simulation step took: Last: 2361.953000 us, Mean: 2410.160786 us, Std: 184.928652 us, N: 192
Apply action took: Last: 73.888001 us, Mean: 70.892340 us, Std: 17.542273 us, N: 194
Newton simulation step took: Last: 2274.202998 us, Mean: 2409.456342 us, Std: 184.707038 us, N: 193
Get dones took: Last: 503.935000 us, Mean: 3176.439361 us, Std: 25855.625066 us, N: 97
Get rewards took: Last: 100.394001 us, Mean: 785.672928 us, Std: 6466.543603 us, N: 97
Reset idx took: Last: 1173.642002 us, Mean: 2392.515064 us, Std: 9785.688885 us, N: 62
Get observations took: Last: 78.683999 us, Mean: 107.013663 us, Std: 201.971979 us, N: 98

You also need to update the timer test: https://github.com/isaac-sim/IsaacLab/blob/main/source/isaaclab/test/utils/test_timer.py

AntoineRichard · 2025-08-21T13:09:25Z

@AntoineRichard Thanks this seems very useful

out of curious, how do you disable or enable the timer just from command line say running a train.py?

Thanks Octi! It's not in yet. But I want to rework the benchmarking to set this global flag to True and add some probing points, in the code. We could add some default args to enable the timer and its display.

AntoineRichard · 2025-08-21T13:10:40Z

Could you update the usage of the class in the docstrings to use these new features? Otherwise they get burried :)

Also now, is it going over per-line of code to get statistics or you had other timers as well in the codebase to log?
Pre physics step took: Last: 13.959998 us, Mean: 16.989330 us, Std: 16.355029 us, N: 97
Apply action took: Last: 57.998001 us, Mean: 70.876819 us, Std: 17.586332 us, N: 193
Newton simulation step took: Last: 2361.953000 us, Mean: 2410.160786 us, Std: 184.928652 us, N: 192
Apply action took: Last: 73.888001 us, Mean: 70.892340 us, Std: 17.542273 us, N: 194
Newton simulation step took: Last: 2274.202998 us, Mean: 2409.456342 us, Std: 184.707038 us, N: 193
Get dones took: Last: 503.935000 us, Mean: 3176.439361 us, Std: 25855.625066 us, N: 97
Get rewards took: Last: 100.394001 us, Mean: 785.672928 us, Std: 6466.543603 us, N: 97
Reset idx took: Last: 1173.642002 us, Mean: 2392.515064 us, Std: 9785.688885 us, N: 62
Get observations took: Last: 78.683999 us, Mean: 107.013663 us, Std: 201.971979 us, N: 98
You also need to update the timer test: https://github.com/isaac-sim/IsaacLab/blob/main/source/isaaclab/test/utils/test_timer.py

I had a bunch of timers where I wanted to measure the time in the direct locomotion envs.
I'll update the tests :)

AntoineRichard · 2025-08-26T08:39:06Z

We could make the decorator one a no-op, but the context manager is trickier.

Here is some early tests with 1e6 function calls, decorated, or within a timer context:

Decorated function with timer enabled took: 0.21423927600062598
Function in timer context with timer enabled took: 0.20318939499975386
Decorated function with timer disabled took: 0.004021803999421536
Function in timer context with timer disabled took: 0.05497912999999244
Function with no timer took: 0.004050381000524794

The decorator method with no-op works well, but the context one is more painful because the object gets created every time we hit the context block.
@Mayankm96

…or context managers and group enable / disable rather than an ugly global flag.

kellyguo11 · 2025-09-05T00:29:27Z

@AntoineRichard are you anticipating more changes for this or is it ready for merge?

AntoineRichard requested a review from pascal-roth August 20, 2025 12:48

AntoineRichard self-assigned this Aug 20, 2025

AntoineRichard requested a review from jtigue-bdai August 20, 2025 12:51

jtigue-bdai approved these changes Aug 20, 2025

View reviewed changes

Mayankm96 reviewed Aug 21, 2025

View reviewed changes

Mayankm96 requested changes Aug 21, 2025

View reviewed changes

AntoineRichard added 7 commits August 21, 2025 15:55

improved timer to track mean and std

852eb4a

better print message

bd50340

added global flags

502b4a3

adding changelog

3c0c1c9

reworked change logs

4fe104c

workign flags

736ef2b

Should have all the requested mods.

6d19bdd

AntoineRichard force-pushed the antoiner/timer_update branch from 67ac7c3 to 6d19bdd Compare August 21, 2025 13:55

pre-commits

d3a3070

ooctipus changed the title ~~improved timer to track mean and std~~ improves timer to track mean and std Aug 21, 2025

ooctipus changed the title ~~improves timer to track mean and std~~ Improves timer to track mean and std Aug 21, 2025

AntoineRichard added 2 commits August 26, 2025 14:37

Reworking timer to support no-op on decorator, faster exit strategy f…

9bec78f

…or context managers and group enable / disable rather than an ugly global flag.

slight rework. Still need to go over all the code and check the doc.

5942c7f

kellyguo11 approved these changes Sep 4, 2025

View reviewed changes

	Online welford's algorithm to compute the mean and std of the elapsed time
	Internal Helpers.

Improves timer to track mean and std #3233

Are you sure you want to change the base?

Improves timer to track mean and std #3233

Conversation

AntoineRichard commented Aug 20, 2025

Description

Type of change

Sample output:

Checklist

Uh oh!

jtigue-bdai left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

ooctipus commented Aug 20, 2025

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Mayankm96 left a comment • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

AntoineRichard commented Aug 21, 2025

Uh oh!

AntoineRichard commented Aug 21, 2025

Uh oh!

AntoineRichard commented Aug 26, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

kellyguo11 commented Sep 5, 2025

Uh oh!

Uh oh!

Mayankm96 left a comment •

edited

Loading

AntoineRichard commented Aug 26, 2025 •

edited

Loading