Skip to content
This repository has been archived by the owner on Nov 17, 2023. It is now read-only.

[OpPerf] Fixed Python profiler bug #17642

Merged
merged 3 commits into from
Feb 26, 2020

Conversation

connorgoggins
Copy link
Contributor

@connorgoggins connorgoggins commented Feb 20, 2020

Description

Currently, the Python profiler for the opperf utility is broken. This fix changes the way args are passed to the underlying op during testing.

Fixes #17640

Checklist

Essentials

  • Changes are complete (i.e. I finished coding on this PR)
  • All changes have test coverage
  • Code is well-documented
  • To the best of my knowledge, examples are either not affected by this change, or have been fixed to be compatible with this change

Changes

  • M benchmark/opperf/utils/profiler_utils.py

Comments

Test suite was run with Python profiler on Mac OS X, building the latest version of MXNet (with my fix) from source.

Full OpPerf test suite - CPU (Native profiler)

Full OpPerf test suite - CPU (Python profiler)

@apeforest

@connorgoggins
Copy link
Contributor Author

@mxnet-label-bot add [pr-awaiting-review]

@@ -248,12 +248,11 @@ def python_profile(func):
@functools.wraps(func)
def python_profile_it(*args, **kwargs):
runs = args[1]
modified_args = (args[0], 1, args[2])
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't remember the reason why we need to write this way in the first place. @ChaiBapchya could you please review. @connorgoggins Have you run through existing tests to make sure this does not break any existing usage?

Copy link
Contributor Author

@connorgoggins connorgoggins Feb 21, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@apeforest yes, ran full OpPerf suite with Python profiler with this change and everything passed (see results here).

Copy link
Contributor

@ChaiBapchya ChaiBapchya Feb 21, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So the args that are passed to this function are
args[0] = op
args[1] = warmup / runs (number of times to run for warmup or number of times to run)
args[2] - rest of the args

https://github.com/apache/incubator-mxnet/blob/9dcf71d8fe33f77ed316a95fcffaf1f7f883ff70/benchmark/opperf/utils/benchmark_utils.py#L114

https://github.com/apache/incubator-mxnet/blob/9dcf71d8fe33f77ed316a95fcffaf1f7f883ff70/benchmark/opperf/utils/benchmark_utils.py#L121

The way it worked for native MXNet CPP profiler is that you could pass the runs (and it would capture the time for each value along with mean/max, etc)

But for Python's time it function, we had to manually run the for loop for the number of runs.
So that's what I did there

  1. we copy the number of runs in a variable in run and then run it that many number of times
  2. For each run, we use python time it function to time it and then take average, mean, max, etc values for each of those individual python time runs.

Makes sense? @apeforest

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ChaiBapchya So basically you are saying we don't need to do this modified_args for python profiler, right? So @connorgoggins change is valid?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We do need to modify the args to meet the requirement for capturing per run timing info using python's time_it function. This needs to handled in a way that doesn't break existing native profiler.

@ChaiBapchya
Copy link
Contributor

preloaded and multi_* ops aren't being tracked for some reason. could you fix that too? @connorgoggins

@apeforest
Copy link
Contributor

preloaded and multi_* ops aren't being tracked for some reason. could you fix that too? @connorgoggins

Let's fix that in a separate PR.

times = []

for _ in range(runs):
start_time = time.perf_counter() # 1
res = func(*modified_args, **kwargs)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@connorgoggins @apeforest
If we pass the *args as is, it will still have
args[0] as op
args[1] as runs
For eg if user passed runs as 10

So the native profiler would run 10 times and so will the for loop run 10 times (for timing Python profiler)

Coz the func here is nd_forward_backward_profile or nd_forward_profile (both take runs as a parameter)

@@ -248,7 +248,7 @@ def python_profile(func):
@functools.wraps(func)
def python_profile_it(*args, **kwargs):
runs = args[1]
modified_args = (args[0], 1, args[2])
modified_args = (args[0], 1)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Now it looks good!

Copy link
Contributor

@ChaiBapchya ChaiBapchya left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks good now! Thanks for the fix!

@apeforest apeforest merged commit 1906eff into apache:master Feb 26, 2020
anirudh2290 pushed a commit to anirudh2290/mxnet that referenced this pull request May 29, 2020
* Changed arg structure in op func call

* Length check to prevent index out of bounds error

* Dropping args[2] as it is no longer used (only using kwargs)
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
pr-awaiting-review PR is waiting for code review
Projects
None yet
Development

Successfully merging this pull request may close these issues.

[OPPERF] opperf error out if I use python timer instead of the builtin mxnet profiler
4 participants