Add Median,p50,p99 to python profiler (#15953)

* median,avg,p90,p99

unused var remove

add parameter

missing arg

add mean, median, p90,p99 to markdown

markdown

* Trigger notification coz of gpu windows fail

* Trigger notification

* Trigger notification

* add _time

benchmark/opperf/utils/benchmark_utils.py

@@ -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)

benchmark/opperf/utils/common_utils.py

@@ -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
@@ -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
 
 
@@ -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:

benchmark/opperf/utils/profiler_utils.py

@@ -17,6 +17,7 @@
 
 import time
 import functools
+import numpy as np
 
 from .common_utils import merge_map_list
 from mxnet import profiler
@@ -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]
@@ -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])
+        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:
@@ -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