profiler.py 12.7 KB
Newer Older
1
#   Copyright (c) 2018 PaddlePaddle Authors. All Rights Reserved.
D
dzhwinter 已提交
2
#
D
dzhwinter 已提交
3 4 5
# Licensed under the Apache License, Version 2.0 (the "License");
# you may not use this file except in compliance with the License.
# You may obtain a copy of the License at
D
dzhwinter 已提交
6
#
D
dzhwinter 已提交
7
#     http://www.apache.org/licenses/LICENSE-2.0
D
dzhwinter 已提交
8
#
D
dzhwinter 已提交
9 10 11 12 13 14
# Unless required by applicable law or agreed to in writing, software
# distributed under the License is distributed on an "AS IS" BASIS,
# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
# See the License for the specific language governing permissions and
# limitations under the License.

15 16
from __future__ import print_function

17
from . import core
S
rename  
sneaxiy 已提交
18
from .wrapped_decorator import signature_safe_contextmanager
19
import os
M
minqiyang 已提交
20
import six
D
dangqingqing 已提交
21

X
Xin Pan 已提交
22 23 24 25
__all__ = [
    'cuda_profiler', 'reset_profiler', 'profiler', 'start_profiler',
    'stop_profiler'
]
D
dangqingqing 已提交
26

D
dangqingqing 已提交
27
NVPROF_CONFIG = [
28 29 30 31 32 33
    "gpustarttimestamp",
    "gpuendtimestamp",
    "gridsize3d",
    "threadblocksize",
    "streamid",
    "enableonstart 0",
D
dangqingqing 已提交
34
    "conckerneltrace",
35 36 37
]


S
rename  
sneaxiy 已提交
38
@signature_safe_contextmanager
D
dangqingqing 已提交
39
def cuda_profiler(output_file, output_mode=None, config=None):
40 41 42
    """
    The CUDA profiler.
    
D
dangqingqing 已提交
43 44
    This fuctions is used to profile CUDA program by CUDA runtime application
    programming interface. The profiling result will be written into
45 46 47 48 49 50
    `output_file`. The users can set the output mode by `output_mode` argument 
    and set the nvidia profiling config by `config` argument. 
    
    After getting the profiling result file, users can use 
    `NVIDIA Visual Profiler <https://developer.nvidia.com/nvidia-visual-profiler>`_ 
    to load this output file to visualize results.
D
dangqingqing 已提交
51 52

    Args:
53
        output_file (str) : The output file name, the result will be
D
dangqingqing 已提交
54
            written into this file.
55 56 57 58 59 60
        output_mode (str, optional) : The output mode has Key-Value pair format ('kvp') 
            and Comma separated values format ('csv', default).
        config (list<str>, optional) : Nvidia profile config. Default config is 
            ['gpustarttimestamp', 'gpuendtimestamp', 'gridsize3d', 'threadblocksize', 
            'streamid', 'enableonstart 0', 'conckerneltrace']. For more details, please
            refer to `Compute Command Line Profiler User Guide <https://developer.download.nvidia.cn/compute/DevZone/docs/html/C/doc/Compute_Command_Line_Profiler_User_Guide.pdf>`_ .
D
Dang Qingqing 已提交
61 62 63 64 65 66 67 68 69 70

    Raises:
        ValueError: If `output_mode` is not in ['kvp', 'csv'].

    Examples:

        .. code-block:: python

            import paddle.fluid as fluid
            import paddle.fluid.profiler as profiler
71
            import numpy as np
D
Dang Qingqing 已提交
72 73 74

            epoc = 8
            dshape = [4, 3, 28, 28]
75
            data = fluid.data(name='data', shape=[None, 3, 28, 28], dtype='float32')
D
Dang Qingqing 已提交
76 77 78 79 80 81 82 83 84 85 86 87 88
            conv = fluid.layers.conv2d(data, 20, 3, stride=[1, 1], padding=[1, 1])

            place = fluid.CUDAPlace(0)
            exe = fluid.Executor(place)
            exe.run(fluid.default_startup_program())

            output_file = 'cuda_profiler.txt'
            with profiler.cuda_profiler(output_file, 'csv') as nvprof:
                for i in range(epoc):
                    input = np.random.random(dshape).astype('float32')
                    exe.run(fluid.default_main_program(), feed={'data': input})
            # then use  NVIDIA Visual Profiler (nvvp) to load this output file
            # to visualize results.
D
dangqingqing 已提交
89 90 91
    """
    if output_mode is None:
        output_mode = 'csv'
D
dangqingqing 已提交
92 93 94
    if output_mode not in ['kvp', 'csv']:
        raise ValueError("The output mode must be 'kvp' or 'csv'.")
    config = NVPROF_CONFIG if config is None else config
95 96
    config_file = 'nvprof_config_file'
    with open(config_file, 'wb') as fp:
M
minqiyang 已提交
97
        fp.writelines([six.b("%s\n" % item) for item in config])
98
    core.nvprof_init(output_file, output_mode, config_file)
D
dangqingqing 已提交
99
    # Enables profiler collection by the active CUDA profiling tool.
D
dangqingqing 已提交
100
    core.nvprof_start()
D
dangqingqing 已提交
101 102
    yield
    # Disables profiler collection.
D
dangqingqing 已提交
103
    core.nvprof_stop()
104
    os.remove(config_file)
105 106 107


def reset_profiler():
D
Dang Qingqing 已提交
108 109 110 111 112 113 114 115 116 117
    """
    Clear the previous time record. This interface does not work for
    `fluid.profiler.cuda_profiler`, it only works for
    `fluid.profiler.start_profiler`, `fluid.profiler.stop_profiler`,
    and `fluid.profiler.profiler`.

    Examples:

        .. code-block:: python

118
            import paddle.fluid as fluid
D
Dang Qingqing 已提交
119
            import paddle.fluid.profiler as profiler
120
            with profiler.profiler('CPU', 'total', '/tmp/profile'):
D
Dang Qingqing 已提交
121 122 123 124
                for iter in range(10):
                    if iter == 2:
                        profiler.reset_profiler()
                    # ...
125
    """
126 127 128
    core.reset_profiler()


X
Xin Pan 已提交
129
def start_profiler(state):
D
Dang Qingqing 已提交
130 131
    """
    Enable the profiler. Uers can use `fluid.profiler.start_profiler` and
132 133
    `fluid.profiler.stop_profiler` to profile, which is equal to the usage 
    of `fluid.profiler.profiler` interface.
X
Xin Pan 已提交
134 135

    Args:
136 137 138 139
        state (str) : The profiling state, which should be one of 'CPU', 'GPU'
            or 'All'. 'CPU' means only profiling CPU; 'GPU' means profiling
            both CPU and GPU; 'All' means profiling both CPU and GPU, and 
            generates timeline as well.
D
Dang Qingqing 已提交
140 141 142 143 144 145 146 147

    Raises:
        ValueError: If `state` is not in ['CPU', 'GPU', 'All'].

    Examples:

        .. code-block:: python

148
            import paddle.fluid as fluid
D
Dang Qingqing 已提交
149 150 151 152 153 154 155 156
            import paddle.fluid.profiler as profiler

            profiler.start_profiler('GPU')
            for iter in range(10):
                if iter == 2:
                    profiler.reset_profiler()
                # except each iteration
            profiler.stop_profiler('total', '/tmp/profile')
X
Xin Pan 已提交
157 158 159
    """
    if core.is_profiler_enabled():
        return
X
Xin Pan 已提交
160 161 162 163 164 165 166 167 168 169 170 171
    if state not in ['CPU', 'GPU', "All"]:
        raise ValueError("The state must be 'CPU' or 'GPU' or 'All'.")
    if state == "GPU":
        prof_state = core.ProfilerState.kCUDA
    elif state == "CPU":
        prof_state = core.ProfilerState.kCPU
    else:
        prof_state = core.ProfilerState.kAll
    core.enable_profiler(prof_state)


def stop_profiler(sorted_key=None, profile_path='/tmp/profile'):
D
Dang Qingqing 已提交
172 173
    """
    Stop the profiler. Uers can use `fluid.profiler.start_profiler` and
174 175
    `fluid.profiler.stop_profiler` to profile, which is equal to the usage 
    of `fluid.profiler.profiler` interface.
X
Xin Pan 已提交
176 177

    Args:
178 179 180 181
        sorted_key (str, optional) : The order of profiling results, which 
            should be one of None, 'calls', 'total', 'max', 'min' or 'ave'.
            Default is None, means the profiling results will be printed
            in the order of first end time of events.
X
Xin Pan 已提交
182 183 184 185 186
            The `calls` means sorting by the number of calls.
            The `total` means sorting by the total execution time.
            The `max` means sorting by the maximum execution time.
            The `min` means sorting by the minimum execution time.
            The `ave` means sorting by the average execution time.
187 188
        profile_path (str, optional) : If state == 'All', it will generate timeline,
            and write it into `profile_path`. The default profile_path is `/tmp/profile`. 
D
Dang Qingqing 已提交
189 190 191 192 193 194 195 196 197

    Raises:
        ValueError: If `sorted_key` is not in
            ['calls', 'total', 'max', 'min', 'ave'].

    Examples:

        .. code-block:: python

198
            import paddle.fluid as fluid
D
Dang Qingqing 已提交
199 200 201 202 203 204 205 206
            import paddle.fluid.profiler as profiler

            profiler.start_profiler('GPU')
            for iter in range(10):
                if iter == 2:
                    profiler.reset_profiler()
                # except each iteration
            profiler.stop_profiler('total', '/tmp/profile')
X
Xin Pan 已提交
207 208 209
    """
    if not core.is_profiler_enabled():
        return
X
Xin Pan 已提交
210 211 212 213 214 215 216 217 218 219 220 221 222 223 224 225 226
    sorted_key = 'default' if sorted_key is None else sorted_key
    if sorted_key not in ['default', 'calls', 'total', 'max', 'min', 'ave']:
        raise ValueError("The sorted_key must be None or in 'calls', 'total', "
                         "'max', 'min' and 'ave'")
    key_map = {
        'default': core.EventSortingKey.kDefault,
        'calls': core.EventSortingKey.kCalls,
        'total': core.EventSortingKey.kTotal,
        'max': core.EventSortingKey.kMax,
        'min': core.EventSortingKey.kMin,
        'ave': core.EventSortingKey.kAve,
    }
    # TODO(qingqing) : redirect C++ ostream to Python stream.
    # with core.ostream_redirect(stdout=True, stderr=True):
    core.disable_profiler(key_map[sorted_key], profile_path)


S
rename  
sneaxiy 已提交
227
@signature_safe_contextmanager
X
Xin Pan 已提交
228
def profiler(state, sorted_key=None, profile_path='/tmp/profile'):
229 230 231
    """
    The profiler interface. Different from `fluid.profiler.cuda_profiler`, 
    this profiler can be used to profile both CPU and GPU program.
232 233

    Args:
234 235 236 237 238 239 240 241
        state (str) : The profiling state, which should be one of 'CPU', 'GPU'
            or 'All'. 'CPU' means only profiling CPU; 'GPU' means profiling
            both CPU and GPU; 'All' means profiling both CPU and GPU, and 
            generates timeline as well.
        sorted_key (str, optional) : The order of profiling results, which 
            should be one of None, 'calls', 'total', 'max', 'min' or 'ave'.
            Default is None, means the profiling results will be printed
            in the order of first end time of events.
242
            The `calls` means sorting by the number of calls.
243 244 245 246
            The `total` means sorting by the total execution time.
            The `max` means sorting by the maximum execution time.
            The `min` means sorting by the minimum execution time.
            The `ave` means sorting by the average execution time.
247 248
        profile_path (str, optional) : If state == 'All', it will generate timeline,
            and write it into `profile_path`. The default profile_path is `/tmp/profile`. 
D
Dang Qingqing 已提交
249 250 251 252 253 254 255 256 257

    Raises:
        ValueError: If `state` is not in ['CPU', 'GPU', 'All']. If `sorted_key` is
            not in ['calls', 'total', 'max', 'min', 'ave'].

    Examples:

        .. code-block:: python

258
            import paddle.fluid as fluid
D
Dang Qingqing 已提交
259
            import paddle.fluid.profiler as profiler
260
            import numpy as np
D
Dang Qingqing 已提交
261

262 263
            epoc = 8
            dshape = [4, 3, 28, 28]
264
            data = fluid.data(name='data', shape=[None, 3, 28, 28], dtype='float32')
265 266 267 268 269 270 271 272 273 274
            conv = fluid.layers.conv2d(data, 20, 3, stride=[1, 1], padding=[1, 1])

            place = fluid.CPUPlace()
            exe = fluid.Executor(place)
            exe.run(fluid.default_startup_program())

            with profiler.profiler('CPU', 'total', '/tmp/profile') as prof:
                for i in range(epoc):
                    input = np.random.random(dshape).astype('float32')
                    exe.run(fluid.default_main_program(), feed={'data': input})
275 276 277 278 279 280 281 282 283 284 285 286 287 288 289 290 291 292 293 294 295 296 297 298 299 300 301 302 303 304 305 306 307 308 309 310 311 312

    Examples Results:

        .. code-block:: text

            #### Examples Results ####
            #### 1) sorted_key = 'total', 'calls', 'max', 'min', 'ave' ####
            # The only difference in 5 sorted_key results is the following sentense: 
            # "Sorted by number of xxx in descending order in the same thread."
            # The reason is that in this example, above 5 columns are already sorted.
            ------------------------->     Profiling Report     <-------------------------

            Place: CPU
            Time unit: ms
            Sorted by total time in descending order in the same thread
            #Sorted by number of calls in descending order in the same thread
            #Sorted by number of max in descending order in the same thread
            #Sorted by number of min in descending order in the same thread
            #Sorted by number of avg in descending order in the same thread

            Event                       Calls       Total       Min.        Max.        Ave.        Ratio.
            thread0::conv2d             8           129.406     0.304303    127.076     16.1758     0.983319
            thread0::elementwise_add    8           2.11865     0.193486    0.525592    0.264832    0.016099
            thread0::feed               8           0.076649    0.006834    0.024616    0.00958112  0.000582432

            #### 2) sorted_key = None  ####
            # Since the profiling results are printed in the order of first end time of Ops,
            # the printed order is feed->conv2d->elementwise_add 
            ------------------------->     Profiling Report     <-------------------------

            Place: CPU
            Time unit: ms
            Sorted by event first end time in descending order in the same thread

            Event                       Calls       Total       Min.        Max.        Ave.        Ratio.
            thread0::feed               8           0.077419    0.006608    0.023349    0.00967738  0.00775934
            thread0::conv2d             8           7.93456     0.291385    5.63342     0.99182     0.795243
            thread0::elementwise_add    8           1.96555     0.191884    0.518004    0.245693    0.196998
313
    """
X
Xin Pan 已提交
314
    start_profiler(state)
315
    yield
X
Xin Pan 已提交
316
    stop_profiler(sorted_key, profile_path)