From d49445fcdc01102bea04e5dd83272f928d557bb6 Mon Sep 17 00:00:00 2001 From: Zhaoqi Zhu Date: Wed, 3 Jul 2019 10:26:04 -0700 Subject: [PATCH] Updating profiler tutorial to include new custom operator profiling (#15403) * update profiler tutorial * Update profiler.md * Update profiler.md * Update profiler.md * Update docs/tutorials/python/profiler.md Co-Authored-By: Aaron Markham * Update docs/tutorials/python/profiler.md Co-Authored-By: Aaron Markham * Update docs/tutorials/python/profiler.md Co-Authored-By: Aaron Markham * Update profiler.md change image url to dmlc and add a code example * Update profiler.md * Update profiler.md * Update profiler.md * Update profiler.md * Re-trigger build * Update profiler.md --- docs/tutorials/python/profiler.md | 75 +++++++++++++++++++++++++++++++ 1 file changed, 75 insertions(+) diff --git a/docs/tutorials/python/profiler.md b/docs/tutorials/python/profiler.md index 9eed452c2e27..f2da62833fcf 100644 --- a/docs/tutorials/python/profiler.md +++ b/docs/tutorials/python/profiler.md @@ -206,6 +206,81 @@ Let's zoom in to check the time taken by operators The above picture visualizes the sequence in which the operators were executed and the time taken by each operator. +### Profiling Custom Operators +Should the existing NDArray operators fail to meet all your model's needs, MXNet supports [Custom Operators](https://mxnet.incubator.apache.org/versions/master/tutorials/gluon/customop.html) that you can define in Python. In `forward()` and `backward()` of a custom operator, there are two kinds of code: "pure Python" code (NumPy operators included) and "sub-operators" (NDArray operators called within `forward()` and `backward()`). With that said, MXNet can profile the execution time of both kinds without additional setup. Specifically, the MXNet profiler will break a single custom operator call into a pure Python event and several sub-operator events if there are any. Furthermore, all of those events will have a prefix in their names, which is, conveniently, the name of the custom operator you called. + +Let's try profiling custom operators with the following code example: + +```python + +import mxnet as mx +from mxnet import nd +from mxnet import profiler + +class MyAddOne(mx.operator.CustomOp): + def forward(self, is_train, req, in_data, out_data, aux): + self.assign(out_data[0], req[0], in_data[0]+1) + + def backward(self, req, out_grad, in_data, out_data, in_grad, aux): + self.assign(in_grad[0], req[0], out_grad[0]) + +@mx.operator.register('MyAddOne') +class CustomAddOneProp(mx.operator.CustomOpProp): + def __init__(self): + super(CustomAddOneProp, self).__init__(need_top_grad=True) + + def list_arguments(self): + return ['data'] + + def list_outputs(self): + return ['output'] + + def infer_shape(self, in_shape): + return [in_shape[0]], [in_shape[0]], [] + + def create_operator(self, ctx, shapes, dtypes): + return MyAddOne() + + +inp = mx.nd.zeros(shape=(500, 500)) + +profiler.set_config(profile_all=True, continuous_dump = True) +profiler.set_state('run') + +w = nd.Custom(inp, op_type="MyAddOne") + +mx.nd.waitall() + +profiler.set_state('stop') +profiler.dump() +``` + +Here, we have created a custom operator called `MyAddOne`, and within its `forward()` function, we simply add one to the input. We can visualize the dump file in `chrome://tracing/`: + +![Custom Operator Profiling Screenshot](https://raw.githubusercontent.com/dmlc/web-data/master/mxnet/tutorials/python/profiler/profiler_output_custom_operator_chrome.png) + +As shown by the screenshot, in the **Custom Operator** domain where all the custom operator-related events fall into, we can easily visualize the execution time of each segment of `MyAddOne`. We can tell that `MyAddOne::pure_python` is executed first. We also know that `CopyCPU2CPU` and `_plus_scalr` are two "sub-operators" of `MyAddOne` and the sequence in which they are executed. + +Please note that: to be able to see the previously described information, you need to set `profile_imperative` to `True` even when you are using custom operators in [symbolic mode](https://mxnet.incubator.apache.org/versions/master/tutorials/basic/symbol.html) (refer to the code snippet below, which is the symbolic-mode equivelent of the code example above). The reason is that within custom operators, pure python code and sub-operators are still called imperatively. + +```python +# Set profile_all to True +profiler.set_config(profile_all=True, aggregate_stats=True, continuous_dump = True) +# OR, Explicitly Set profile_symbolic and profile_imperative to True +profiler.set_config(profile_symbolic = True, profile_imperative = True, \ + aggregate_stats=True, continuous_dump = True) + +profiler.set_state('run') +# Use Symbolic Mode +a = mx.symbol.Variable('a') +b = mx.symbol.Custom(data=a, op_type='MyAddOne') +c = b.bind(mx.cpu(), {'a': inp}) +y = c.forward() +mx.nd.waitall() +profiler.set_state('stop') +profiler.dump() +``` + ## Advanced: Using NVIDIA Profiling Tools MXNet's Profiler is the recommended starting point for profiling MXNet code, but NVIDIA also provides a couple of tools for low-level profiling of CUDA code: [NVProf](https://devblogs.nvidia.com/cuda-pro-tip-nvprof-your-handy-universal-gpu-profiler/), [Visual Profiler](https://developer.nvidia.com/nvidia-visual-profiler) and [Nsight Compute](https://developer.nvidia.com/nsight-compute). You can use these tools to profile all kinds of executables, so they can be used for profiling Python scripts running MXNet. And you can use these in conjunction with the MXNet Profiler to see high-level information from MXNet alongside the low-level CUDA kernel information.