From 687fc0fa897bdf26cc7ffce403a93f79f7254c58 Mon Sep 17 00:00:00 2001 From: "Shunting Zhang (Meta Employee)" Date: Tue, 20 Feb 2024 08:34:06 -0800 Subject: [PATCH] tiny improvement to the cprofile wrapper (#120100) Summary: 1. right now we double increment the profile counter. The PR avoid that so we don't end up with profile_0, profile_2, profile_4 ... 2. log the latency to run the passed in function with profiling on so we can easily skip those _compile call which returns quickly. X-link: https://github.com/pytorch/pytorch/pull/120100 Approved by: https://github.com/eellison Reviewed By: huydhn Differential Revision: D53930648 Pulled By: shunting314 fbshipit-source-id: e7af70f52c655453c5d7b3d7c82aa3e17f69b1df --- userbenchmark/dynamo/dynamobench/_dynamo/utils.py | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/userbenchmark/dynamo/dynamobench/_dynamo/utils.py b/userbenchmark/dynamo/dynamobench/_dynamo/utils.py index 089b25a1bc..2dca191fb5 100644 --- a/userbenchmark/dynamo/dynamobench/_dynamo/utils.py +++ b/userbenchmark/dynamo/dynamobench/_dynamo/utils.py @@ -131,12 +131,17 @@ def cprofile_wrapper(func): @wraps(func) def profile_wrapper(*args, **kwargs): global timer_counter - profile_path = Path(func.__name__ + f"{next(timer_counter)}.profile") + profile_cnt = next(timer_counter) + profile_path = Path(func.__name__ + f"{profile_cnt}.profile") prof = cProfile.Profile() prof.enable() + start_ts = time.time() retval = prof.runcall(func, *args, **kwargs) + profile_latency = time.time() - start_ts prof.disable() - print(f"### Cprofile for {func.__name__} iter {next(timer_counter)} ###") + print( + f"### Cprofile for {func.__name__} iter {profile_cnt} took {profile_latency:.3f} seconds ###" + ) ps = pstats.Stats(prof) prof.dump_stats(profile_path) svg_path = profile_path.with_suffix(".svg")