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

Add Median/p50, p90, p99 to python profiler #15953

Merged
merged 6 commits into from
Aug 26, 2019
Merged

Add Median/p50, p90, p99 to python profiler #15953

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
6 commits
Select commit Hold shift + click to select a range
d226c38
median,avg,p90,p99
ChaiBapchya Aug 20, 2019
3c890b3
Trigger notification coz of gpu windows fail
ChaiBapchya Aug 21, 2019
3dc6efb
Merge branch 'master' into median,p50,p99
ChaiBapchya Aug 21, 2019
a941e0a
Trigger notification
ChaiBapchya Aug 21, 2019
b46ecae
Trigger notification
ChaiBapchya Aug 23, 2019
5a56aa3
add _time
ChaiBapchya Aug 23, 2019
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion benchmark/opperf/utils/benchmark_utils.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -50,7 +50,7 @@ def _prepare_op_inputs(inputs, run_backward, dtype, ctx):
return args_list, kwargs_list


def _run_nd_operator_performance_test(op, inputs, run_backward, warmup, runs, kwargs_list, profiler):
def _run_nd_operator_performance_test(op, inputs, run_backward, warmup, runs, args_list, kwargs_list, profiler):
if profiler == 'native':
if run_backward:
benchmark_helper_func = cpp_profile(nd_forward_backward_and_profile)
Expand Down
17 changes: 14 additions & 3 deletions benchmark/opperf/utils/common_utils.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -97,6 +97,10 @@ def _prepare_op_benchmark_result(op, op_bench_result, profiler):
max_mem_usage = "---"
inputs = "---"
avg_time = "---"
p50_time = "---"
p90_time = "---"
p99_time = "---"

for key, value in op_bench_result.items():
if "avg_time_forward" in key:
avg_forward_time = value
Expand All @@ -108,12 +112,19 @@ def _prepare_op_benchmark_result(op, op_bench_result, profiler):
inputs = value
elif "avg_time" in key:
avg_time = value
elif "p50_time" in key:
p50_time = value
elif "p90_time" in key:
p90_time = value
elif "p99_time" in key:
p99_time = value

result = ""
if profiler == "native":
result = "| {} | {} | {} | {} | {} |".format(operator_name,
avg_forward_time, avg_backward_time, max_mem_usage, inputs)
elif profiler == "python":
result = "| {} | {} | {} |".format(operator_name, avg_time, inputs)
result = "| {} | {} | {} | {} | {} | {} |".format(operator_name, avg_time, p50_time, p90_time, p99_time, inputs)
return result


Expand All @@ -132,8 +143,8 @@ def _prepare_markdown(results, runtime_features=None, profiler='native'):
" | Inputs |")
elif profiler == 'python':
results_markdown.append(
"| Operator | Avg Time (ms) | Inputs |")
results_markdown.append("| :---: | :---: | :---: |")
"| Operator | Avg Time (ms) | P50 Time (ms) | P90 Time (ms) | P99 Time (ms) | Inputs |")
results_markdown.append("| :---: | :---: | :---: | :---: | :---: | :---: |")

for op, op_bench_results in sorted(results.items(), key=itemgetter(0)):
for op_bench_result in op_bench_results:
Expand Down
29 changes: 24 additions & 5 deletions benchmark/opperf/utils/profiler_utils.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@

import time
import functools
import numpy as np

from .common_utils import merge_map_list
from mxnet import profiler
Expand Down Expand Up @@ -219,6 +220,9 @@ def python_profile(func):
res, timing output. res being result returned after operator execution.
profiler output is a dictionary with summary of operation execution.
Example output : { "add": [{"avg_time_add": 0.4053089120425284,
'p50_time_add': 16.761042876169086,
'p90_time_add': 18.081666342914108,
'p99_time_add': 19.060144051909447,
"inputs": {
"lhs": [1024, 1024],
"rhs": [1024,1024]
Expand All @@ -228,10 +232,16 @@ def python_profile(func):

@functools.wraps(func)
def python_profile_it(*args, **kwargs):
start_time = time.perf_counter() # 1
res = func(*args, **kwargs)
end_time = time.perf_counter() # 2
run_time = end_time - start_time # 3
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.

Can you give an example case what are now sent in modified_args ?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Currently when you run opperf
args are - [op, runs, args]
runs is the # of times we want to run this operator

For python profiler to work, we need to call the operator explicitly those many times
Hence runs = args[1] stores the number of times user wanted to run the operator

Now, the alias takes the argument to run MXNet profiler on it
We're overwriting on that, hence we pass run=1 to MXNet profiler
modified args = [op, 1, args]
Does that answer your question?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

This is where we decide which profiler to call (selects which decorator to use 'cpp' or 'python'

https://github.com/ChaiBapchya/incubator-mxnet/blob/5a56aa3580e2f78a1a78581fe8b8f179962a3a5a/benchmark/opperf/utils/benchmark_utils.py#L56

The reason why I had to modify the args, was because I wanted to reuse the function

https://github.com/ChaiBapchya/incubator-mxnet/blob/cba7c4e360d843d523b29be7fb52fa220fcafa92/benchmark/opperf/utils/ndarray_utils.py#L23

Here it runs the operator runs number of times. But I can't add python time functions here as it will change the behavior of the function for python as well as cpp decorator. Hence I had to override the function by modifying the arguments passed.

times = []

for _ in range(runs):
start_time = time.perf_counter() # 1
res = func(*modified_args, **kwargs)
end_time = time.perf_counter() # 2
run_time = (end_time - start_time)*1000 # 3
times.append(run_time)

# NOTE : same as cpp_profile_it
if len(args) > 0:
Expand All @@ -241,6 +251,15 @@ def python_profile_it(*args, **kwargs):
else:
raise ValueError("Unable to identify operator name to extract profiler output!")

profiler_output = {'avg_time_'+str(operator_name): run_time}
avg_run_time = np.mean(times)
p50_run_time = np.percentile(times, 50)
p90_run_time = np.percentile(times, 90)
p99_run_time = np.percentile(times, 99)

profiler_output = {'avg_time_'+str(operator_name): avg_run_time,
'p50_time_'+str(operator_name): p50_run_time,
'p90_time_'+str(operator_name): p90_run_time,
'p99_time_'+str(operator_name): p99_run_time,
}
return res, profiler_output
return python_profile_it