profiler_statistic.py 74.0 KB
Newer Older
C
chenjian 已提交
1
# Copyright (c) 2022 PaddlePaddle Authors. All Rights Reserved.
C
chenjian 已提交
2
#
C
chenjian 已提交
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
C
chenjian 已提交
6
#
C
chenjian 已提交
7
#     http://www.apache.org/licenses/LICENSE-2.0
C
chenjian 已提交
8
#
C
chenjian 已提交
9 10 11 12 13 14 15
# 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.
import collections
from enum import Enum
C
chenjian 已提交
16
import re
C
chenjian 已提交
17

18
from paddle.fluid.core import TracerEventType, TracerMemEventType
C
chenjian 已提交
19

20
from .statistic_helper import intersection_ranges, merge_ranges, merge_self_ranges, sum_ranges
C
chenjian 已提交
21 22 23 24 25 26 27 28 29 30 31

_AllTracerEventType = [
    TracerEventType.Operator, TracerEventType.Dataloader,
    TracerEventType.ProfileStep, TracerEventType.CudaRuntime,
    TracerEventType.Kernel, TracerEventType.Memcpy, TracerEventType.Memset,
    TracerEventType.UserDefined, TracerEventType.OperatorInner,
    TracerEventType.Forward, TracerEventType.Backward,
    TracerEventType.Optimization, TracerEventType.Communication,
    TracerEventType.PythonOp, TracerEventType.PythonUserDefined
]

C
chenjian 已提交
32
_CommunicationOpName = ['allreduce', 'broadcast', 'rpc']
C
chenjian 已提交
33

C
chenjian 已提交
34 35 36

class SortedKeys(Enum):
    r"""
C
chenjian 已提交
37
    SortedKeys is used to specify how to sort items when printing :ref:`summary <api_paddle_profiler_profiler_summary>` table.
C
chenjian 已提交
38

C
chenjian 已提交
39
    The meaning of each SortedKeys is as following
C
chenjian 已提交
40

C
chenjian 已提交
41
    - **SortedKeys.CPUTotal** :  Sorted by CPU total time.
C
chenjian 已提交
42

C
chenjian 已提交
43
    - **SortedKeys.CPUAvg**  : Sorted by CPU average time.
C
chenjian 已提交
44

C
chenjian 已提交
45
    - **SortedKeys.CPUMax**  : Sorted by CPU max time.
C
chenjian 已提交
46

C
chenjian 已提交
47
    - **SortedKeys.CPUMin**  : Sorted by CPU min time.
C
chenjian 已提交
48

C
chenjian 已提交
49
    - **SortedKeys.GPUTotal**  : Sorted by GPU total time.
C
chenjian 已提交
50

C
chenjian 已提交
51
    - **SortedKeys.GPUAvg**  : Sorted by GPU average time.
C
chenjian 已提交
52

C
chenjian 已提交
53 54 55
    - **SortedKeys.GPUMax**  : Sorted by GPU max time.

    - **SortedKeys.GPUMin**  : Sorted by GPU min time.
C
chenjian 已提交
56 57 58 59 60 61 62 63 64
    """
    CPUTotal = 0
    CPUAvg = 1
    CPUMax = 2
    CPUMin = 3
    GPUTotal = 4
    GPUAvg = 5
    GPUMax = 6
    GPUMin = 7
C
chenjian 已提交
65 66 67 68 69 70 71 72 73 74 75 76 77


class HostStatisticNode:
    r'''
    Wrap original node for calculating statistic metrics.
    '''

    def __init__(self, hostnode):
        self.hostnode = hostnode
        self.children_node = []
        self.runtime_node = []
        self.cpu_time = 0
        self.self_cpu_time = 0
C
chenjian 已提交
78
        self.gpu_time = 0  # kernel time
C
chenjian 已提交
79
        self.self_gpu_time = 0
C
chenjian 已提交
80 81
        self.general_gpu_time = 0  # besides kernel, include time of gpu events like memcpy and memset
        self.self_general_gpu_time = 0
C
chenjian 已提交
82 83 84 85 86 87 88

    def cal_statistic(self):
        for child in self.children_node:
            child.cal_statistic()
        for rt in self.runtime_node:
            rt.cal_statistic()
        self.cpu_time = self.hostnode.end_ns - self.hostnode.start_ns
89
        self.self_cpu_time = self.cpu_time
C
chenjian 已提交
90 91
        for child in self.children_node:
            self.gpu_time += child.gpu_time
C
chenjian 已提交
92
            self.general_gpu_time += child.general_gpu_time
C
chenjian 已提交
93 94 95 96 97
            self.self_cpu_time -= (child.end_ns - child.start_ns)
        for rt in self.runtime_node:
            self.self_cpu_time -= (rt.end_ns - rt.start_ns)
            self.gpu_time += rt.gpu_time
            self.self_gpu_time += rt.gpu_time
C
chenjian 已提交
98 99
            self.general_gpu_time += rt.general_gpu_time
            self.self_general_gpu_time += rt.general_gpu_time
C
chenjian 已提交
100
        for device in self.hostnode.device_node:
C
chenjian 已提交
101 102 103 104 105
            if device.type == TracerEventType.Kernel:
                self.gpu_time += (device.end_ns - device.start_ns)
                self.self_gpu_time += (device.end_ns - device.start_ns)
            self.general_gpu_time += (device.end_ns - device.start_ns)
            self.self_general_gpu_time += (device.end_ns - device.start_ns)
C
chenjian 已提交
106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132

    @property
    def end_ns(self):
        return self.hostnode.end_ns

    @property
    def start_ns(self):
        return self.hostnode.start_ns

    def __getattr__(self, name):
        return getattr(self.hostnode, name)


def traverse_tree(nodetrees):
    results = collections.defaultdict(list)
    for thread_id, rootnode in nodetrees.items():
        stack = []
        stack.append(rootnode)
        threadlist = results[thread_id]
        while stack:
            current_node = stack.pop()
            threadlist.append(current_node)
            for childnode in current_node.children_node:
                stack.append(childnode)
    return results


C
chenjian 已提交
133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149
def get_device_nodes(hostnode):
    '''
    Get all device nodes called in the time range of hostnode.
    '''
    stack = []
    device_nodes = []
    stack.append(hostnode)
    while stack:
        current_node = stack.pop()
        for childnode in current_node.children_node:
            stack.append(childnode)
        for runtimenode in current_node.runtime_node:
            for devicenode in runtimenode.device_node:
                device_nodes.append(devicenode)
    return device_nodes


C
chenjian 已提交
150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195
def wrap_tree(nodetrees):
    '''
    Using HostStatisticNode to wrap original profiler result tree, and calculate node statistic metrics.
    '''
    node_statistic_tree = {}
    results = collections.defaultdict(list)
    newresults = collections.defaultdict(list)
    for thread_id, rootnode in nodetrees.items():
        stack = []
        stack.append(rootnode)
        root_statistic_node = HostStatisticNode(rootnode)
        newstack = []
        newstack.append(root_statistic_node)
        node_statistic_tree[thread_id] = root_statistic_node
        threadlist = results[thread_id]
        newthreadlist = newresults[thread_id]
        while stack:
            current_node = stack.pop()
            threadlist.append(current_node)
            current_statistic_node = newstack.pop()
            newthreadlist.append(current_statistic_node)
            for childnode in current_node.children_node:
                stack.append(childnode)
                child_statistic_node = HostStatisticNode(childnode)
                current_statistic_node.children_node.append(
                    child_statistic_node)
                newstack.append(child_statistic_node)
            for runtimenode in current_node.runtime_node:
                runtime_statistic_node = HostStatisticNode(runtimenode)
                current_statistic_node.runtime_node.append(
                    runtime_statistic_node)
    # recursive calculate node statistic values
    for thread_id, root_statistic_node in node_statistic_tree.items():
        root_statistic_node.cal_statistic()

    return node_statistic_tree, newresults


class TimeRangeSummary:
    r"""
    Analyse time ranges for each TracerEventType, and summarize the time.
    """

    def __init__(self):
        self.CPUTimeRange = collections.defaultdict(list)
        self.GPUTimeRange = collections.defaultdict(
196 197
            lambda: collections.defaultdict(
                list))  # GPU events should be divided into different devices
C
chenjian 已提交
198 199 200 201 202 203 204 205 206 207 208 209 210
        self.CPUTimeRangeSum = collections.defaultdict(int)
        self.GPUTimeRangeSum = collections.defaultdict(
            lambda: collections.defaultdict(int))
        self.call_times = collections.defaultdict(int)

    def parse(self, nodetrees):
        r"""
        Analysis node trees in profiler result, and get time range for different tracer event type.
        """
        thread2hostnodes = traverse_tree(nodetrees)
        for threadid, hostnodes in thread2hostnodes.items():
            CPUTimeRange = collections.defaultdict(list)
            GPUTimeRange = collections.defaultdict(
211 212
                lambda: collections.defaultdict(lambda: collections.defaultdict(
                    list)))  # device_id/type/stream_id
C
chenjian 已提交
213 214 215 216 217 218 219 220 221 222 223 224 225 226 227 228 229 230 231 232 233
            for hostnode in hostnodes[1:]:  #skip root node
                CPUTimeRange[hostnode.type].append(
                    (hostnode.start_ns, hostnode.end_ns))
                self.call_times[hostnode.type] += 1
                for runtimenode in hostnode.runtime_node:
                    CPUTimeRange[runtimenode.type].append(
                        (runtimenode.start_ns, runtimenode.end_ns))
                    self.call_times[runtimenode.type] += 1
                    for devicenode in runtimenode.device_node:
                        GPUTimeRange[devicenode.device_id][devicenode.type][
                            devicenode.stream_id].append(
                                (devicenode.start_ns, devicenode.end_ns))
                        self.call_times[devicenode.type] += 1

            for event_type, time_ranges in CPUTimeRange.items():
                time_ranges = merge_self_ranges(time_ranges, is_sorted=False)
                self.CPUTimeRange[event_type] = merge_ranges(
                    self.CPUTimeRange[event_type], time_ranges, is_sorted=True)
            for device_id, device_time_ranges in GPUTimeRange.items():
                for event_type, event_time_ranges in device_time_ranges.items():
                    for stream_id, time_ranges in event_time_ranges.items():
234 235
                        time_ranges = merge_self_ranges(time_ranges,
                                                        is_sorted=False)
C
chenjian 已提交
236 237 238 239 240 241 242 243 244 245 246 247 248 249 250 251 252 253 254 255 256 257
                        self.GPUTimeRange[device_id][event_type] = merge_ranges(
                            self.GPUTimeRange[device_id][event_type],
                            time_ranges,
                            is_sorted=True)

        for event_type, time_ranges in self.CPUTimeRange.items():
            self.CPUTimeRangeSum[event_type] = sum_ranges(time_ranges)
        for device_id, device_time_ranges in self.GPUTimeRange.items():
            for event_type, time_ranges in device_time_ranges.items():
                self.GPUTimeRangeSum[device_id][event_type] = sum_ranges(
                    time_ranges)

    def get_gpu_devices(self):
        return self.GPUTimeRange.keys()

    def get_gpu_range_sum(self, device_id, event_type):
        return self.GPUTimeRangeSum[device_id][event_type]

    def get_cpu_range_sum(self, event_type):
        return self.CPUTimeRangeSum[event_type]


C
chenjian 已提交
258 259 260 261 262 263 264 265 266 267 268 269
class DistributedSummary:
    r"""
    Analysis communication and computation time range, and their overlap.
    The computation time is all kernel except kernels for communication like nccl.
    """

    def __init__(self):
        self.cpu_communication_range = []
        self.gpu_communication_range = []
        self.communication_range = []
        self.computation_range = []
        self.overlap_range = []
C
chenjian 已提交
270 271
        self.cpu_calls = 0
        self.gpu_calls = 0
C
chenjian 已提交
272 273 274 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

    def parse(self, nodetrees):
        '''
        Collect all communication and computation time ranges.
        '''
        thread2hostnodes = traverse_tree(nodetrees)
        for threadid, hostnodes in thread2hostnodes.items():
            for hostnode in hostnodes[1:]:  #skip root node
                # case 1: TracerEventType is Communication
                if hostnode.type == TracerEventType.Communication:
                    self.cpu_communication_range.append(
                        (hostnode.start_ns, hostnode.end_ns))
                    device_nodes = get_device_nodes(hostnode)
                    for device_node in device_nodes:
                        if device_node.type == TracerEventType.Kernel:
                            self.gpu_communication_range.append(
                                (device_node.start_ns, device_node.end_ns))

                #case 2: TracerEventType is Operator but is communication op
                elif hostnode.type == TracerEventType.Operator and any([
                        name in hostnode.name.lower()
                        for name in _CommunicationOpName
                ]):
                    self.cpu_communication_range.append(
                        (hostnode.start_ns, hostnode.end_ns))
                    device_nodes = get_device_nodes(hostnode)
                    for device_node in device_nodes:
                        if device_node.type == TracerEventType.Kernel:
                            self.gpu_communication_range.append(
                                (device_node.start_ns, device_node.end_ns))

                #case 3: Others, filter kernels named with nccl
                else:
                    for runtimenode in hostnode.runtime_node:
                        for devicenode in runtimenode.device_node:
                            if devicenode.type == TracerEventType.Kernel:
                                if 'nccl' in devicenode.name.lower():
309 310 311
                                    self.gpu_communication_range.append(
                                        (devicenode.start_ns,
                                         devicenode.end_ns))
C
chenjian 已提交
312
                                else:
313 314 315
                                    self.computation_range.append(
                                        (devicenode.start_ns,
                                         devicenode.end_ns))
C
chenjian 已提交
316 317
        self.cpu_calls = len(set(self.cpu_communication_range))
        self.gpu_calls = len(set(self.gpu_communication_range))
C
chenjian 已提交
318 319 320 321
        self.cpu_communication_range = merge_self_ranges(
            self.cpu_communication_range, is_sorted=False)
        self.gpu_communication_range = merge_self_ranges(
            self.gpu_communication_range, is_sorted=False)
322 323 324 325 326 327 328 329
        self.communication_range = merge_ranges(self.cpu_communication_range,
                                                self.gpu_communication_range,
                                                is_sorted=True)
        self.computation_range = merge_self_ranges(self.computation_range,
                                                   is_sorted=False)
        self.overlap_range = intersection_ranges(self.communication_range,
                                                 self.computation_range,
                                                 is_sorted=True)
C
chenjian 已提交
330 331


C
chenjian 已提交
332 333 334 335 336 337
class EventSummary:
    r"""
    Analyse operator event in profiling data, correlate with its device event.
    """

    class DeviceItem:
338

C
chenjian 已提交
339 340 341 342 343 344 345 346 347 348 349 350 351 352 353 354 355 356 357 358 359 360 361
        def __init__(self, name):
            self.name = name
            self.call = 0
            self.gpu_time = 0
            self.max_gpu_time = 0
            self.min_gpu_time = float('inf')

        @property
        def avg_gpu_time(self):
            return self.gpu_time / self.call

        def add_gpu_time(self, time):
            if time > self.max_gpu_time:
                self.max_gpu_time = time
            if time < self.min_gpu_time:
                self.min_gpu_time = time
            self.gpu_time += time

        def add_item(self, node):
            self.call += 1
            self.add_gpu_time(node.end_ns - node.start_ns)

    class OperatorItem:
362

C
chenjian 已提交
363 364 365 366 367 368 369 370 371 372 373
        def __init__(self, name):
            self.name = name
            self.call = 0
            self.cpu_time = 0
            self.gpu_time = 0
            self.max_cpu_time = 0
            self.min_cpu_time = float('inf')
            self.max_gpu_time = 0
            self.min_gpu_time = float('inf')
            self.devices = {}
            self.operator_inners = {}
C
chenjian 已提交
374 375 376
            self.general_gpu_time = 0
            self.min_general_gpu_time = float('inf')
            self.max_general_gpu_time = 0
C
chenjian 已提交
377 378 379 380 381 382 383 384 385

        @property
        def avg_cpu_time(self):
            return self.cpu_time / self.call

        @property
        def avg_gpu_time(self):
            return self.gpu_time / self.call

C
chenjian 已提交
386 387 388 389
        @property
        def avg_general_gpu_time(self):
            return self.general_gpu_time / self.call

C
chenjian 已提交
390 391 392 393 394 395 396 397 398 399 400 401 402 403
        def add_cpu_time(self, time):
            if time > self.max_cpu_time:
                self.max_cpu_time = time
            if time < self.min_cpu_time:
                self.min_cpu_time = time
            self.cpu_time += time

        def add_gpu_time(self, time):
            if time > self.max_gpu_time:
                self.max_gpu_time = time
            if time < self.min_gpu_time:
                self.min_gpu_time = time
            self.gpu_time += time

C
chenjian 已提交
404 405 406 407 408 409 410
        def add_general_gpu_time(self, time):
            if time > self.max_general_gpu_time:
                self.max_general_gpu_time = time
            if time < self.min_general_gpu_time:
                self.min_general_gpu_time = time
            self.general_gpu_time += time

C
chenjian 已提交
411 412 413 414 415 416 417
        def add_call(self):
            self.call += 1

        def add_item(self, node):
            self.add_call()
            self.add_cpu_time(node.cpu_time)
            self.add_gpu_time(node.gpu_time)
C
chenjian 已提交
418
            self.add_general_gpu_time(node.general_gpu_time)
C
chenjian 已提交
419
            for child in node.children_node:
C
chenjian 已提交
420 421 422 423 424
                if child.type != TracerEventType.Operator:
                    if child.name not in self.operator_inners:
                        self.operator_inners[
                            child.name] = EventSummary.OperatorItem(child.name)
                    self.operator_inners[child.name].add_item(child)
C
chenjian 已提交
425 426 427

            for runtimenode in node.runtime_node:
                for devicenode in runtimenode.device_node:
428 429 430 431
                    name = devicenode.name
                    if name not in self.devices:
                        self.devices[name] = EventSummary.DeviceItem(name)
                    self.devices[name].add_item(devicenode)
C
chenjian 已提交
432 433

    class GeneralItem:
434

C
chenjian 已提交
435 436 437 438 439 440 441 442 443
        def __init__(self, name):
            self.name = name
            self.call = 0
            self.cpu_time = 0
            self.max_cpu_time = 0
            self.min_cpu_time = float('inf')
            self.gpu_time = 0
            self.max_gpu_time = 0
            self.min_gpu_time = float('inf')
C
chenjian 已提交
444 445 446
            self.general_gpu_time = 0
            self.min_general_gpu_time = float('inf')
            self.max_general_gpu_time = 0
C
chenjian 已提交
447 448 449 450 451 452 453 454 455

        @property
        def avg_cpu_time(self):
            return self.cpu_time / self.call

        @property
        def avg_gpu_time(self):
            return self.gpu_time / self.call

C
chenjian 已提交
456 457 458 459
        @property
        def avg_general_gpu_time(self):
            return self.general_gpu_time / self.call

C
chenjian 已提交
460 461 462 463 464 465 466 467 468 469 470 471 472 473
        def add_cpu_time(self, time):
            if time > self.max_cpu_time:
                self.max_cpu_time = time
            if time < self.min_cpu_time:
                self.min_cpu_time = time
            self.cpu_time += time

        def add_gpu_time(self, time):
            if time > self.max_gpu_time:
                self.max_gpu_time = time
            if time < self.min_gpu_time:
                self.min_gpu_time = time
            self.gpu_time += time

C
chenjian 已提交
474 475 476 477 478 479 480
        def add_general_gpu_time(self, time):
            if time > self.max_general_gpu_time:
                self.max_general_gpu_time = time
            if time < self.min_general_gpu_time:
                self.min_general_gpu_time = time
            self.general_gpu_time += time

C
chenjian 已提交
481 482 483 484 485 486 487
        def add_call(self):
            self.call += 1

        def add_item(self, node):
            self.add_call()
            self.add_cpu_time(node.cpu_time)
            self.add_gpu_time(node.gpu_time)
C
chenjian 已提交
488
            self.add_general_gpu_time(node.general_gpu_time)
C
chenjian 已提交
489 490 491 492 493 494 495 496 497 498

    def __init__(self):
        self.items = {}  # for operator summary
        self.thread_items = collections.defaultdict(
            dict)  # for operator summary
        self.userdefined_items = {}  # for userdefined summary
        self.userdefined_thread_items = collections.defaultdict(
            dict)  # for userdefined summary
        self.model_perspective_items = {}  # for model summary
        self.memory_manipulation_items = {}  # for memory manipulation summary
499
        self.kernel_items = {}  # for kernel summary
C
chenjian 已提交
500 501 502 503 504 505 506 507 508 509 510 511 512 513 514 515 516 517

    def parse(self, nodetrees):
        r"""
        Analysis operator event in the nodetress.
        """
        node_statistic_trees, thread2host_statistic_nodes = wrap_tree(nodetrees)
        for threadid, host_statistic_nodes in thread2host_statistic_nodes.items(
        ):
            for host_statistic_node in host_statistic_nodes[
                    1:]:  #skip root node
                if host_statistic_node.type == TracerEventType.Operator:
                    self.add_operator_item(host_statistic_node)
                if host_statistic_node.type == TracerEventType.UserDefined\
                    or host_statistic_node.type == TracerEventType.PythonUserDefined:
                    if 'memcpy' in host_statistic_node.name.lower() or 'memorycopy' in host_statistic_node.name.lower()\
                        or 'memset' in host_statistic_node.name.lower():
                        self.add_memory_manipulation_item(host_statistic_node)
                    else:
518 519
                        if host_statistic_node.type == TracerEventType.PythonUserDefined:
                            self.add_userdefined_item(host_statistic_node)
520
            self.add_kernel_item(host_statistic_nodes[0])
C
chenjian 已提交
521 522 523 524 525 526 527 528 529 530 531 532

        for threadid, root_statistic_node in node_statistic_trees.items():
            deque = collections.deque()
            deque.append(root_statistic_node)
            while deque:
                current_node = deque.popleft()
                for child in current_node.children_node:
                    if child.type == TracerEventType.Forward or child.type == TracerEventType.Dataloader\
                        or child.type == TracerEventType.Backward or child.type == TracerEventType.Optimization:
                        self.add_model_perspective_item(
                            child)  #find first model perspective node
                    else:
C
chenjian 已提交
533 534
                        if child.type == TracerEventType.ProfileStep:
                            self.add_model_perspective_item(child)
C
chenjian 已提交
535 536 537 538 539 540 541 542 543 544 545 546 547 548 549 550 551 552 553 554 555 556 557 558 559 560 561 562 563 564 565 566 567 568 569 570 571 572 573 574 575 576 577 578 579 580 581 582 583
                        deque.append(child)

    def add_operator_item(self, operator_node):
        if operator_node.name not in self.items:
            self.items[operator_node.name] = EventSummary.OperatorItem(
                operator_node.name)

        self.items[operator_node.name].add_item(operator_node)

        if operator_node.name not in self.thread_items[operator_node.thread_id]:
            self.thread_items[operator_node.thread_id][
                operator_node.name] = EventSummary.OperatorItem(
                    operator_node.name)
        self.thread_items[operator_node.thread_id][operator_node.name].add_item(
            operator_node)

    def add_userdefined_item(self, userdefined_node):
        if userdefined_node.name not in self.userdefined_items:
            self.userdefined_items[
                userdefined_node.name] = EventSummary.GeneralItem(
                    userdefined_node.name)

        self.userdefined_items[userdefined_node.name].add_item(userdefined_node)

        if userdefined_node.name not in self.userdefined_thread_items[
                userdefined_node.thread_id]:
            self.userdefined_thread_items[userdefined_node.thread_id][
                userdefined_node.name] = EventSummary.GeneralItem(
                    userdefined_node.name)
        self.userdefined_thread_items[userdefined_node.thread_id][
            userdefined_node.name].add_item(userdefined_node)

    def add_memory_manipulation_item(self, memory_manipulation_node):
        if memory_manipulation_node.name not in self.memory_manipulation_items:
            self.memory_manipulation_items[
                memory_manipulation_node.name] = EventSummary.GeneralItem(
                    memory_manipulation_node.name)
        self.memory_manipulation_items[memory_manipulation_node.name].add_item(
            memory_manipulation_node)

    def add_model_perspective_item(self, model_perspective_node):
        if model_perspective_node.type == TracerEventType.Forward:
            name = 'Forward'
        elif model_perspective_node.type == TracerEventType.Backward:
            name = 'Backward'
        elif model_perspective_node.type == TracerEventType.Optimization:
            name = 'Optimization'
        elif model_perspective_node.type == TracerEventType.Dataloader:
            name = 'Dataloader'
C
chenjian 已提交
584 585
        elif model_perspective_node.type == TracerEventType.ProfileStep:
            name = 'ProfileStep'
C
chenjian 已提交
586 587 588 589 590 591
        else:
            return
        if name not in self.model_perspective_items:
            self.model_perspective_items[name] = EventSummary.GeneralItem(name)
        self.model_perspective_items[name].add_item(model_perspective_node)

592 593 594 595 596 597 598 599 600
    def add_kernel_item(self, root_node):
        device_nodes = get_device_nodes(root_node)
        for device_node in device_nodes:
            if device_node.type == TracerEventType.Kernel:
                name = device_node.name
                if name not in self.kernel_items:
                    self.kernel_items[name] = EventSummary.DeviceItem(name)
                self.kernel_items[name].add_item(device_node)

C
chenjian 已提交
601

602 603 604 605 606 607 608 609 610 611 612 613 614 615 616 617 618 619 620 621 622 623 624 625 626 627 628 629 630 631 632 633 634 635 636 637 638 639 640 641 642 643 644 645 646 647 648 649 650 651 652 653 654 655 656 657 658 659 660 661 662 663 664 665 666 667 668 669 670 671 672 673 674 675 676 677 678
class MemorySummary:
    r"""
    Analyse memory events in profiling data.
    """

    class MemoryItem:

        def __init__(self, event_name, place, memory_type='Allocated'):
            self.event_name = event_name
            self.place = place
            self.allocation_count = 0
            self.free_count = 0
            self.allocation_size = 0
            self.free_size = 0
            self.increase_size = 0
            self.memory_type = memory_type

        def add_memory_record(self, size, allocation_type):
            if allocation_type == TracerMemEventType.Allocate or allocation_type == TracerMemEventType.ReservedAllocate:
                self.allocation_count += 1
                self.allocation_size += size

            elif allocation_type == TracerMemEventType.Free or allocation_type == TracerMemEventType.ReservedFree:
                self.free_count += 1
                self.free_size -= size  # size is sign(-) when free.

            else:
                print("No corresponding type.")
            self.increase_size = self.allocation_size - self.free_size

    def __init__(self):
        self.allocated_items = collections.defaultdict(
            dict)  # for memory summary, device type: event
        self.reserved_items = collections.defaultdict(
            dict)  # for memory summary, device type: event
        self.peak_allocation_values = collections.defaultdict(int)
        self.peak_reserved_values = collections.defaultdict(int)

    def _analyse_node_memory(self, event_name, node):
        for memnode in node.mem_node:  # self mem node
            if memnode.type == TracerMemEventType.Allocate or memnode.type == TracerMemEventType.Free:
                if event_name not in self.allocated_items[memnode.place]:
                    self.allocated_items[
                        memnode.place][event_name] = MemorySummary.MemoryItem(
                            event_name, memnode.place, 'Allocated')
                self.allocated_items[
                    memnode.place][event_name].add_memory_record(
                        memnode.increase_bytes, memnode.type)
            elif memnode.type == TracerMemEventType.ReservedAllocate or memnode.type == TracerMemEventType.ReservedFree:
                if event_name not in self.reserved_items[memnode.place]:
                    self.reserved_items[
                        memnode.place][event_name] = MemorySummary.MemoryItem(
                            event_name, memnode.place, 'Reserved')
                self.reserved_items[
                    memnode.place][event_name].add_memory_record(
                        memnode.increase_bytes, memnode.type)
            self.peak_allocation_values[memnode.place] = max(
                self.peak_allocation_values[memnode.place],
                memnode.peak_allocated)
            self.peak_reserved_values[memnode.place] = max(
                self.peak_reserved_values[memnode.place], memnode.peak_reserved)

    def parse(self, nodetrees):
        r"""
        Analyse memory event in the nodetress.
        """
        thread2hostnodes = traverse_tree(nodetrees)
        for threadid, host_nodes in thread2hostnodes.items():
            for host_node in host_nodes[1:]:  #skip root node
                if host_node.type == TracerEventType.OperatorInner:
                    continue
                if host_node.type == TracerEventType.Operator:
                    for child in host_node.children_node:
                        self._analyse_node_memory(host_node.name, child)
                self._analyse_node_memory(host_node.name, host_node)


C
chenjian 已提交
679 680 681 682 683 684 685 686 687 688
class StatisticData:
    r"""
    Hold all analysed results.
    """

    def __init__(self, node_trees, extra_info):
        self.node_trees = node_trees
        self.extra_info = extra_info
        self.time_range_summary = TimeRangeSummary()
        self.event_summary = EventSummary()
C
chenjian 已提交
689
        self.distributed_summary = DistributedSummary()
690
        self.memory_summary = MemorySummary()
C
chenjian 已提交
691 692
        self.time_range_summary.parse(node_trees)
        self.event_summary.parse(node_trees)
C
chenjian 已提交
693
        self.distributed_summary.parse(node_trees)
694
        self.memory_summary.parse(node_trees)
C
chenjian 已提交
695 696 697 698 699 700 701 702


def _build_table(statistic_data,
                 sorted_by=SortedKeys.CPUTotal,
                 op_detail=True,
                 thread_sep=False,
                 time_unit='ms',
                 row_limit=100,
703 704 705 706
                 max_src_column_width=75,
                 views=None):

    from .profiler import SummaryView
C
chenjian 已提交
707 708 709 710 711 712 713 714 715 716 717 718 719 720 721 722 723 724 725 726 727 728 729 730 731 732 733 734 735 736 737 738 739 740 741 742 743 744 745 746 747 748 749 750 751 752 753 754 755
    """Prints a summary of events."""
    # format table row
    SPACING_SIZE = 2
    row_format_list = [""]
    header_sep_list = [""]
    line_length_list = [-SPACING_SIZE]

    def add_column(padding, text_dir='<'):
        row_format_list[0] += '{: ' + text_dir + str(padding) + '}' + (
            ' ' * SPACING_SIZE)
        header_sep_list[0] += '-' * padding + (' ' * SPACING_SIZE)
        line_length_list[0] += padding + SPACING_SIZE

    def add_title(padding, text):
        left_length = padding - len(text)
        half = left_length // 2
        return '-' * half + text + '-' * (left_length - half)

    result = []

    def append(s):
        result.append(s)
        result.append('\n')

    def format_time(time, unit='ms', indent=0):
        r"""
        Transform time in ns to time in unit.
        """
        if time == float('inf'):
            return '-'
        else:
            result = float(time)
            if unit == 's':
                result /= 1e9
            elif unit == 'ms':
                result /= 1e6
            elif unit == 'us':
                result /= 1e3
            return '{}{:.2f}'.format(' ' * indent, result)

    def format_ratio(ratio, indent=0):
        r"""
        Transform ratio within [0, 1] to percentage presentation.
        """
        return '{}{:.2f}'.format(' ' * indent, ratio * 100)

    total_time = statistic_data.time_range_summary.get_cpu_range_sum(
        TracerEventType.ProfileStep)

756
    if views is None or SummaryView.DeviceView in views:
C
chenjian 已提交
757

758 759 760 761
        ###### Print Device Summary ######
        headers = ['Device', 'Utilization (%)']
        name_column_width = 30
        DEFAULT_COLUMN_WIDTH = 20
C
chenjian 已提交
762
        add_column(name_column_width)
763 764
        for _ in headers[1:]:
            add_column(DEFAULT_COLUMN_WIDTH)
C
chenjian 已提交
765 766 767 768 769 770

        row_format = row_format_list[0]
        header_sep = header_sep_list[0]
        line_length = line_length_list[0]

        # construct table string
771 772

        append(add_title(line_length, "Device Summary"))
C
chenjian 已提交
773 774
        append(header_sep)
        append(row_format.format(*headers))
C
chenjian 已提交
775
        append(header_sep)
776 777 778 779 780 781 782 783 784 785 786 787 788 789 790 791 792 793
        row_values = [
            'CPU(Process)',
            format_ratio(
                float(statistic_data.extra_info['Process Cpu Utilization']))
        ]
        append(row_format.format(*row_values))
        row_values = [
            'CPU(System)',
            format_ratio(
                float(statistic_data.extra_info['System Cpu Utilization']))
        ]
        append(row_format.format(*row_values))
        for gpu_name in statistic_data.time_range_summary.get_gpu_devices():
            gpu_time = float(
                statistic_data.time_range_summary.get_gpu_range_sum(
                    gpu_name, TracerEventType.Kernel))
            utilization = gpu_time / total_time
            row_values = ['GPU{}'.format(gpu_name), format_ratio(utilization)]
C
chenjian 已提交
794
            append(row_format.format(*row_values))
795

C
chenjian 已提交
796 797
        append(header_sep)
        append(
798 799 800
            "Note:\nCPU(Process) Utilization = Current process CPU time over all cpu cores / elapsed time, so max utilization can be reached 100% * number of cpu cores.\n"
            "CPU(System) Utilization = All processes CPU time over all cpu cores(busy time) / (busy time + idle time).\n"
            "GPU Utilization = Current process GPU time / elapsed time.")
C
chenjian 已提交
801
        append('-' * line_length)
C
chenjian 已提交
802 803 804
        append('')
        append('')

805 806 807 808 809 810
        if total_time == 0:
            return ''.join(result)

    if views is None or SummaryView.OverView in views:
        ###### Print Overview Summary ######
        headers = ['Event Type', 'Calls', 'CPU Time', 'Ratio (%)']
C
chenjian 已提交
811 812 813 814
        row_format_list = [""]
        header_sep_list = [""]
        line_length_list = [-SPACING_SIZE]

C
chenjian 已提交
815
        DEFAULT_COLUMN_WIDTH = 25
C
chenjian 已提交
816 817 818 819 820 821 822 823
        for _ in headers:
            add_column(DEFAULT_COLUMN_WIDTH)

        row_format = row_format_list[0]
        header_sep = header_sep_list[0]
        line_length = line_length_list[0]

        # construct table string
824
        append(add_title(line_length, "Overview Summary"))
C
chenjian 已提交
825 826 827 828
        append('Time unit: {}'.format(time_unit))
        append(header_sep)
        append(row_format.format(*headers))
        append(header_sep)
829 830 831 832 833 834 835 836 837 838 839 840 841 842 843 844 845
        cpu_type_time = collections.defaultdict(int)
        gpu_type_time = collections.defaultdict(int)
        cpu_call_times = collections.defaultdict(int)
        gpu_call_times = collections.defaultdict(int)
        cpu_call_times.update(statistic_data.time_range_summary.call_times)
        gpu_call_times.update(statistic_data.time_range_summary.call_times)

        for event_type, value in statistic_data.time_range_summary.CPUTimeRangeSum.items(
        ):
            if event_type != TracerEventType.Communication:
                cpu_type_time[event_type] = value
        if statistic_data.distributed_summary.cpu_communication_range:
            cpu_type_time[TracerEventType.Communication] = sum_ranges(
                statistic_data.distributed_summary.cpu_communication_range)
            cpu_call_times[
                TracerEventType.
                Communication] = statistic_data.distributed_summary.cpu_calls
C
chenjian 已提交
846

847 848 849 850 851 852 853 854 855 856 857 858 859 860 861 862 863 864 865 866 867 868 869 870 871 872 873 874 875 876 877 878
        for event_type in [
                TracerEventType.Dataloader, TracerEventType.Forward,
                TracerEventType.Backward, TracerEventType.Optimization
        ]:
            event_type_name = str(event_type).split('.')[1]
            if event_type in cpu_call_times and event_type_name in statistic_data.event_summary.model_perspective_items:
                cpu_call_times[
                    event_type] = statistic_data.event_summary.model_perspective_items[
                        event_type_name].call
                cpu_type_time[
                    event_type] = statistic_data.event_summary.model_perspective_items[
                        event_type_name].cpu_time

        gpu_time_range = collections.defaultdict(list)
        for device_id, device_time_ranges in statistic_data.time_range_summary.GPUTimeRange.items(
        ):
            for event_type, time_range in device_time_ranges.items():
                gpu_time_range[event_type] = merge_ranges(
                    gpu_time_range[event_type], time_range, is_sorted=True)
        for event_type, time_range in gpu_time_range.items():
            gpu_type_time[event_type] = sum_ranges(time_range)
        if statistic_data.distributed_summary.gpu_communication_range:
            gpu_type_time[TracerEventType.Communication] = sum_ranges(
                statistic_data.distributed_summary.gpu_communication_range)
            gpu_call_times[
                TracerEventType.
                Communication] = statistic_data.distributed_summary.gpu_calls

        sorted_items = sorted(cpu_type_time.items(),
                              key=lambda x: x[1],
                              reverse=True)
        event_type, time = sorted_items[0]
C
chenjian 已提交
879
        row_values = [
880 881 882 883
            '{}'.format(str(event_type).split('.')[1]),
            cpu_call_times[event_type],
            format_time(time, unit=time_unit),
            format_ratio(float(time) / total_time)
C
chenjian 已提交
884 885
        ]
        append(row_format.format(*row_values))
886 887 888 889 890 891 892 893 894 895 896 897 898 899 900 901 902 903 904 905
        for event_type, time in sorted_items[1:]:
            row_values = [
                '  {}'.format(str(event_type).split('.')[1]),
                cpu_call_times[event_type],
                format_time(time, unit=time_unit),
                format_ratio(float(time) / total_time)
            ]
            append(row_format.format(*row_values))
        append(header_sep)
        headers = ['', 'Calls', 'GPU Time', 'Ratio (%)']
        append(row_format.format(*headers))
        append(header_sep)
        for event_type, time in gpu_type_time.items():
            row_values = [
                '  {}'.format(str(event_type).split('.')[1]),
                gpu_call_times[event_type],
                format_time(time, unit=time_unit),
                format_ratio(float(time) / total_time)
            ]
            append(row_format.format(*row_values))
C
chenjian 已提交
906 907 908

        append(header_sep)
        append(
909 910 911 912
            "Note:\nIn this table, We sum up all collected events in terms of event type.\n"
            "The time of events collected on host are presented as CPU Time, and as GPU Time if on device.\n"
            "Events with different types may overlap or inclusion, e.g. Operator includes OperatorInner, so the sum of ratios is not 100%.\n"
            "The time of events in the same type with overlap will not calculate twice, and all time is summed after merged.\n"
C
chenjian 已提交
913
            "Example:\n"
914 915 916 917 918 919
            "Thread 1:\n"
            "  Operator: |___________|     |__________|\n"
            "Thread 2:\n"
            "  Operator:   |____________|     |___|\n"
            "After merged:\n"
            "  Result:   |______________|  |__________|\n")
C
chenjian 已提交
920 921 922 923
        append('-' * line_length)
        append('')
        append('')

924
    if views is None or SummaryView.ModelView in views:
925

926 927 928 929 930 931 932 933 934 935 936 937 938 939 940 941 942 943 944 945 946 947 948 949 950 951 952 953 954 955 956 957 958 959 960 961 962 963 964 965 966 967 968 969 970 971 972 973 974 975 976 977 978 979 980 981 982 983 984 985 986 987 988 989 990 991 992 993 994 995 996 997 998 999 1000 1001 1002 1003 1004
        ###### Print Model Summary Report ######
        model_perspective_items = statistic_data.event_summary.model_perspective_items
        if len(model_perspective_items) > 1:
            all_row_values = []
            accmulation_time = 0
            gpu_accmulation_time = 0
            gpu_total_time = statistic_data.event_summary.model_perspective_items[
                'ProfileStep'].gpu_time
            for name in [
                    'ProfileStep', 'Dataloader', 'Forward', 'Backward',
                    'Optimization'
            ]:
                if name in model_perspective_items:
                    item = model_perspective_items[name]
                    if gpu_total_time == 0:
                        gpu_ratio = 0
                    else:
                        gpu_ratio = float(item.gpu_time) / gpu_total_time
                    name = '{}'.format(
                        name) if 'ProfileStep' in name else '  {}'.format(name)
                    row_values = [
                        '{}'.format(name), item.call,
                        '{} / {} / {} / {} / {}'.format(
                            format_time(item.cpu_time, unit=time_unit),
                            format_time(item.avg_cpu_time, unit=time_unit),
                            format_time(item.max_cpu_time, unit=time_unit),
                            format_time(item.min_cpu_time, unit=time_unit),
                            format_ratio(float(item.cpu_time) / total_time)),
                        '{} / {} / {} / {} / {}'.format(
                            format_time(item.gpu_time, unit=time_unit),
                            format_time(item.avg_gpu_time, unit=time_unit),
                            format_time(item.max_gpu_time, unit=time_unit),
                            format_time(item.min_gpu_time, unit=time_unit),
                            format_ratio(gpu_ratio))
                    ]
                    all_row_values.append(row_values)
                    if 'ProfileStep' not in name:
                        accmulation_time += item.cpu_time
                        gpu_accmulation_time += item.gpu_time

            other_time = total_time - accmulation_time
            other_gpu_time = gpu_total_time - gpu_accmulation_time
            if gpu_total_time == 0:
                gpu_ratio = 0
            else:
                gpu_ratio = float(other_gpu_time) / gpu_total_time
            row_values = [
                '  Others', '-', '{} / - / - / - / {}'.format(
                    format_time(other_time, unit=time_unit),
                    format_ratio(float(other_time) / total_time)),
                '{} / - / - / - / {}'.format(
                    format_time(other_gpu_time, unit=time_unit),
                    format_ratio(gpu_ratio))
            ]
            all_row_values.append(row_values)
            # Calculate the column width
            calltime_width = 6
            cpu_data_description_width = 40
            gpu_data_description_width = 40
            for row_values in all_row_values:
                if isinstance(row_values[1],
                              int) and len(str(row_values[1])) > calltime_width:
                    calltime_width = len(str(row_values[1]))
                if len(row_values[2]) > cpu_data_description_width:
                    cpu_data_description_width = len(row_values[2])
                if len(row_values[3]) > gpu_data_description_width:
                    gpu_data_description_width = len(row_values[3])
            headers = [
                'Name', 'Calls', 'CPU Total / Avg / Max / Min / Ratio(%)',
                'GPU Total / Avg / Max / Min / Ratio(%)'
            ]
            row_format_list = [""]
            header_sep_list = [""]
            line_length_list = [-SPACING_SIZE]
            name_column_width = 15
            add_column(name_column_width)
            add_column(calltime_width)
            add_column(cpu_data_description_width)
            add_column(gpu_data_description_width)
C
chenjian 已提交
1005

1006 1007 1008 1009 1010 1011 1012 1013 1014 1015 1016 1017 1018 1019 1020 1021 1022 1023 1024 1025 1026 1027 1028 1029 1030 1031 1032 1033 1034 1035 1036 1037 1038 1039 1040 1041 1042 1043 1044 1045 1046 1047 1048 1049 1050 1051 1052 1053 1054 1055 1056 1057 1058 1059 1060 1061 1062 1063 1064 1065 1066 1067 1068 1069 1070 1071 1072 1073 1074 1075 1076 1077 1078 1079 1080 1081 1082 1083 1084 1085 1086 1087 1088 1089 1090 1091 1092 1093 1094 1095 1096 1097 1098 1099 1100 1101 1102 1103 1104 1105 1106 1107 1108 1109 1110 1111 1112 1113 1114 1115 1116 1117 1118 1119 1120 1121 1122 1123 1124 1125 1126 1127 1128 1129 1130 1131 1132 1133 1134 1135 1136 1137 1138 1139 1140 1141 1142 1143 1144 1145 1146 1147 1148 1149 1150 1151 1152 1153 1154 1155 1156 1157 1158 1159 1160 1161 1162 1163 1164 1165 1166 1167 1168 1169 1170 1171 1172 1173 1174 1175 1176 1177 1178 1179 1180 1181 1182 1183 1184 1185 1186 1187 1188 1189 1190 1191 1192 1193 1194 1195 1196 1197 1198 1199 1200 1201 1202 1203 1204 1205 1206 1207 1208 1209 1210 1211 1212 1213 1214 1215 1216 1217 1218 1219 1220 1221 1222 1223 1224 1225 1226 1227 1228 1229 1230 1231 1232 1233 1234 1235 1236 1237 1238 1239 1240 1241 1242 1243 1244 1245 1246 1247 1248 1249 1250 1251 1252 1253 1254 1255 1256 1257
            row_format = row_format_list[0]
            header_sep = header_sep_list[0]
            line_length = line_length_list[0]

            # construct table string
            append(add_title(line_length, "Model Summary"))
            append('Time unit: {}'.format(time_unit))
            append(header_sep)
            append(row_format.format(*headers))
            append(header_sep)
            for row_values in all_row_values:
                append(row_format.format(*row_values))
            append(header_sep)
            append(
                "Note:\nIn this table, GPU time is the sum of all device(GPU) events called in the phase.\n"
                "Unlike overview summary, if two device(GPU) events execute on different streams with overlap time, we sum them directly here.\n"
            )
            append('-' * line_length)
            append('')
            append('')

    if views is None or SummaryView.DistributedView in views:

        ###### Print Distribution Summary Report ######
        if statistic_data.distributed_summary.communication_range:
            headers = [
                'Name',
                'Total Time',
                'Ratio (%)',
            ]
            row_format_list = [""]
            header_sep_list = [""]
            line_length_list = [-SPACING_SIZE]

            DEFAULT_COLUMN_WIDTH = 25
            for _ in headers:
                add_column(DEFAULT_COLUMN_WIDTH)

            row_format = row_format_list[0]
            header_sep = header_sep_list[0]
            line_length = line_length_list[0]

            # construct table string
            append(add_title(line_length, "Distribution Summary"))
            append('Time unit: {}'.format(time_unit))
            append(header_sep)
            append(row_format.format(*headers))
            append(header_sep)
            communication_time = sum_ranges(
                statistic_data.distributed_summary.communication_range)
            computation_time = sum_ranges(
                statistic_data.distributed_summary.computation_range)
            overlap_time = sum_ranges(
                statistic_data.distributed_summary.overlap_range)
            row_values = [
                'ProfileStep',
                format_time(total_time, unit=time_unit),
                format_ratio(float(total_time) / total_time)
            ]
            append(row_format.format(*row_values))
            row_values = [
                '  Communication',
                format_time(communication_time, unit=time_unit),
                format_ratio(float(communication_time) / total_time)
            ]
            append(row_format.format(*row_values))

            row_values = [
                '  Computation',
                format_time(computation_time, unit=time_unit),
                format_ratio(float(computation_time) / total_time)
            ]
            append(row_format.format(*row_values))

            row_values = [
                '  Overlap',
                format_time(overlap_time, unit=time_unit),
                format_ratio(float(overlap_time) / total_time)
            ]
            append(row_format.format(*row_values))
            append(header_sep)
            append(
                "Note:\nCommunication time: Communication Event time, Communication Op time and its kernel time on gpu.\n"
                "Computation time: Kernel time, except kernels belong to communication(nccl kernels).\n"
                "Overlap time: Communication time intersects with computation time.\n"
                "Example:\n"
                "Communication:\n"
                "  CPU:              |_________________|\n"
                "  GPU:                                  |______________|\n"
                "  Total:            |_________________| |______________|\n"
                "Computation time(Kernel):\n"
                "  GPU:         |________________|\n"
                "Overlap time:       |___________|\n")
            append('-' * line_length)
            append('')
            append('')

    if views is None or SummaryView.OperatorView in views:

        ###### Print Operator Summary Report ######
        if statistic_data.event_summary.items:
            all_row_values = []
            name_column_width = 52
            if thread_sep == True:
                thread_items = statistic_data.event_summary.thread_items
            else:
                thread_items = {
                    'All threads merged': statistic_data.event_summary.items
                }
            for thread_id, items in thread_items.items():
                all_row_values.append("Thread: {}".format(thread_id))
                if sorted_by == SortedKeys.CPUTotal:
                    sorted_items = sorted(items.items(),
                                          key=lambda x: x[1].cpu_time,
                                          reverse=True)
                elif sorted_by == SortedKeys.CPUAvg:
                    sorted_items = sorted(items.items(),
                                          key=lambda x: x[1].avg_cpu_time,
                                          reverse=True)
                elif sorted_by == SortedKeys.CPUMax:
                    sorted_items = sorted(items.items(),
                                          key=lambda x: x[1].max_cpu_time,
                                          reverse=True)
                elif sorted_by == SortedKeys.CPUMin:
                    sorted_items = sorted(items.items(),
                                          key=lambda x: x[1].min_cpu_time)
                elif sorted_by == SortedKeys.GPUTotal:
                    sorted_items = sorted(items.items(),
                                          key=lambda x: x[1].general_gpu_time,
                                          reverse=True)
                elif sorted_by == SortedKeys.GPUAvg:
                    sorted_items = sorted(
                        items.items(),
                        key=lambda x: x[1].avg_general_gpu_time,
                        reverse=True)
                elif sorted_by == SortedKeys.GPUMax:
                    sorted_items = sorted(
                        items.items(),
                        key=lambda x: x[1].max_general_gpu_time,
                        reverse=True)
                elif sorted_by == SortedKeys.GPUMin:
                    sorted_items = sorted(
                        items.items(), key=lambda x: x[1].min_general_gpu_time)
                total_op_cpu_time = 0
                total_op_gpu_time = 0

                for name, item in sorted_items:
                    total_op_cpu_time += item.cpu_time
                    total_op_gpu_time += item.general_gpu_time

                for name, item in sorted_items:
                    if total_op_cpu_time == 0:
                        cpu_ratio = 0
                    else:
                        cpu_ratio = float(item.cpu_time) / total_op_cpu_time
                    if total_op_gpu_time == 0:
                        gpu_ratio = 0
                    else:
                        gpu_ratio = float(
                            item.general_gpu_time) / total_op_gpu_time
                    row_values = [
                        name, item.call, '{} / {} / {} / {} / {}'.format(
                            format_time(item.cpu_time, unit=time_unit),
                            format_time(item.avg_cpu_time, unit=time_unit),
                            format_time(item.max_cpu_time, unit=time_unit),
                            format_time(item.min_cpu_time, unit=time_unit),
                            format_ratio(cpu_ratio)),
                        '{} / {} / {} / {} / {}'.format(
                            format_time(item.general_gpu_time, unit=time_unit),
                            format_time(item.avg_general_gpu_time,
                                        unit=time_unit),
                            format_time(item.max_general_gpu_time,
                                        unit=time_unit),
                            format_time(item.min_general_gpu_time,
                                        unit=time_unit),
                            format_ratio(gpu_ratio))
                    ]
                    all_row_values.append(row_values)
                    if op_detail:
                        for innerop_name, innerop_node in item.operator_inners.items(
                        ):
                            if item.cpu_time == 0:
                                cpu_ratio = 0
                            else:
                                cpu_ratio = float(
                                    innerop_node.cpu_time) / item.cpu_time
                            if item.general_gpu_time == 0:
                                gpu_ratio = 0
                            else:
                                gpu_ratio = float(innerop_node.general_gpu_time
                                                  ) / item.general_gpu_time
                            if len(innerop_name) + 2 > name_column_width:
                                innerop_name = innerop_name[:name_column_width -
                                                            5]
                                innerop_name += "..."
                            row_values = [
                                '  {}'.format(innerop_name), innerop_node.call,
                                '{} / {} / {} / {} / {}'.format(
                                    format_time(innerop_node.cpu_time,
                                                unit=time_unit),
                                    format_time(innerop_node.avg_cpu_time,
                                                unit=time_unit),
                                    format_time(innerop_node.max_cpu_time,
                                                unit=time_unit),
                                    format_time(innerop_node.min_cpu_time,
                                                unit=time_unit),
                                    format_ratio(cpu_ratio)),
                                '{} / {} / {} / {} / {}'.format(
                                    format_time(innerop_node.general_gpu_time,
                                                unit=time_unit),
                                    format_time(
                                        innerop_node.avg_general_gpu_time,
                                        unit=time_unit),
                                    format_time(
                                        innerop_node.max_general_gpu_time,
                                        unit=time_unit),
                                    format_time(
                                        innerop_node.min_general_gpu_time,
                                        unit=time_unit),
                                    format_ratio(gpu_ratio))
                            ]
                            all_row_values.append(row_values)
                            for device_node_name, device_node in innerop_node.devices.items(
                            ):
                                if innerop_node.general_gpu_time == 0:
                                    gpu_ratio = 0
                                else:
                                    gpu_ratio = float(
                                        device_node.gpu_time
                                    ) / innerop_node.general_gpu_time
                                if len(device_node_name
                                       ) + 4 > name_column_width:
                                    device_node_name = device_node_name[:
                                                                        name_column_width
                                                                        - 7]
                                    device_node_name += "..."
                                row_values = [
                                    '    {}'.format(device_node_name),
                                    device_node.call, '- / - / - / - / -',
                                    '{} / {} / {} / {} / {}'.format(
                                        format_time(device_node.gpu_time,
                                                    unit=time_unit),
                                        format_time(device_node.avg_gpu_time,
                                                    unit=time_unit),
                                        format_time(device_node.max_gpu_time,
                                                    unit=time_unit),
                                        format_time(device_node.min_gpu_time,
                                                    unit=time_unit),
                                        format_ratio(gpu_ratio))
                                ]
                                all_row_values.append(row_values)
                        for device_node_name, device_node in item.devices.items(
C
chenjian 已提交
1258
                        ):
1259
                            if item.general_gpu_time == 0:
1260 1261
                                gpu_ratio = 0
                            else:
1262 1263 1264
                                gpu_ratio = float(device_node.gpu_time
                                                  ) / item.general_gpu_time
                            if len(device_node_name) + 2 > name_column_width:
C
chenjian 已提交
1265 1266
                                device_node_name = device_node_name[:
                                                                    name_column_width
1267
                                                                    - 5]
C
chenjian 已提交
1268 1269
                                device_node_name += "..."
                            row_values = [
1270
                                '  {}'.format(device_node_name),
C
chenjian 已提交
1271
                                device_node.call, '- / - / - / - / -',
C
chenjian 已提交
1272
                                '{} / {} / {} / {} / {}'.format(
1273 1274 1275 1276 1277 1278 1279 1280
                                    format_time(device_node.gpu_time,
                                                unit=time_unit),
                                    format_time(device_node.avg_gpu_time,
                                                unit=time_unit),
                                    format_time(device_node.max_gpu_time,
                                                unit=time_unit),
                                    format_time(device_node.min_gpu_time,
                                                unit=time_unit),
1281
                                    format_ratio(gpu_ratio))
C
chenjian 已提交
1282
                            ]
C
chenjian 已提交
1283
                            all_row_values.append(row_values)
1284 1285 1286 1287 1288 1289 1290 1291 1292 1293 1294 1295 1296 1297 1298 1299 1300
            # Calculate the column width
            calltime_width = 6
            cpu_data_description_width = 40
            gpu_data_description_width = 40
            for row_values in all_row_values:
                if isinstance(row_values, str):
                    continue
                if isinstance(row_values[1],
                              int) and len(str(row_values[1])) > calltime_width:
                    calltime_width = len(str(row_values[1]))
                if len(row_values[2]) > cpu_data_description_width:
                    cpu_data_description_width = len(row_values[2])
                if len(row_values[3]) > gpu_data_description_width:
                    gpu_data_description_width = len(row_values[3])
            headers = [
                'Name', 'Calls', 'CPU Total / Avg / Max / Min / Ratio(%)',
                'GPU Total / Avg / Max / Min / Ratio(%)'
1301
            ]
1302 1303 1304 1305 1306 1307 1308
            row_format_list = [""]
            header_sep_list = [""]
            line_length_list = [-SPACING_SIZE]
            add_column(name_column_width)
            add_column(calltime_width)
            add_column(cpu_data_description_width)
            add_column(gpu_data_description_width)
1309

1310 1311 1312
            row_format = row_format_list[0]
            header_sep = header_sep_list[0]
            line_length = line_length_list[0]
1313

1314 1315 1316 1317 1318 1319 1320 1321 1322 1323 1324 1325 1326 1327
            # construct table string
            append(add_title(line_length, "Operator Summary"))
            append('Time unit: {}'.format(time_unit))
            append(header_sep)
            append(row_format.format(*headers))
            append(header_sep)
            for row_values in all_row_values:
                if isinstance(row_values, str):
                    append(add_title(line_length, row_values))
                else:
                    append(row_format.format(*row_values))
            append(header_sep)
            append('')
            append('')
1328

1329
    if views is None or SummaryView.KernelView in views:
1330

1331 1332 1333 1334 1335 1336 1337 1338 1339 1340 1341 1342 1343 1344 1345
        ###### Print Kernel Summary Report ######
        if statistic_data.event_summary.kernel_items:
            all_row_values = []
            kernel_items = statistic_data.event_summary.kernel_items
            if sorted_by == SortedKeys.GPUAvg:
                sorted_items = sorted(kernel_items.items(),
                                      key=lambda x: x[1].avg_gpu_time,
                                      reverse=True)
            elif sorted_by == SortedKeys.GPUMax:
                sorted_items = sorted(kernel_items.items(),
                                      key=lambda x: x[1].max_gpu_time,
                                      reverse=True)
            elif sorted_by == SortedKeys.GPUMin:
                sorted_items = sorted(kernel_items.items(),
                                      key=lambda x: x[1].min_gpu_time)
1346
            else:
1347 1348 1349
                sorted_items = sorted(kernel_items.items(),
                                      key=lambda x: x[1].gpu_time,
                                      reverse=True)
1350

1351 1352 1353 1354 1355 1356 1357 1358 1359 1360 1361 1362 1363 1364 1365 1366 1367 1368 1369 1370 1371 1372
            total_kernel_gpu_time = 0
            for name, item in sorted_items:
                total_kernel_gpu_time += item.gpu_time
            for name, item in sorted_items:
                if total_kernel_gpu_time == 0:
                    gpu_ratio = 0
                else:
                    gpu_ratio = float(item.gpu_time) / total_kernel_gpu_time
                row_values = [
                    name,
                    item.call,
                    '{} / {} / {} / {} / {}'.format(
                        format_time(item.gpu_time, unit=time_unit),
                        format_time(item.avg_gpu_time, unit=time_unit),
                        format_time(item.max_gpu_time, unit=time_unit),
                        format_time(item.min_gpu_time, unit=time_unit),
                        format_ratio(gpu_ratio)),
                ]
                all_row_values.append(row_values)

            headers = [
                'Name', 'Calls', 'GPU Total / Avg / Max / Min / Ratio(%)'
C
chenjian 已提交
1373
            ]
1374 1375 1376 1377 1378 1379 1380 1381 1382 1383
            # Calculate the column width
            name_column_width = 90
            calltime_width = 6
            gpu_data_description_width = 40
            for row_values in all_row_values:
                if isinstance(row_values[1],
                              int) and len(str(row_values[1])) > calltime_width:
                    calltime_width = len(str(row_values[1]))
                if len(row_values[2]) > gpu_data_description_width:
                    gpu_data_description_width = len(row_values[2])
C
chenjian 已提交
1384

1385 1386 1387 1388 1389 1390
            row_format_list = [""]
            header_sep_list = [""]
            line_length_list = [-SPACING_SIZE]
            add_column(name_column_width)
            add_column(calltime_width)
            add_column(gpu_data_description_width)
C
chenjian 已提交
1391

1392 1393 1394
            row_format = row_format_list[0]
            header_sep = header_sep_list[0]
            line_length = line_length_list[0]
C
chenjian 已提交
1395

1396 1397 1398 1399 1400 1401 1402 1403 1404 1405 1406 1407 1408 1409 1410 1411 1412 1413 1414 1415 1416
            # construct table string
            append(add_title(line_length, "Kernel Summary"))
            append('Time unit: {}'.format(time_unit))
            append(header_sep)
            append(row_format.format(*headers))
            append(header_sep)
            kernel_name_pattern = re.compile('(.+?)(<.*>)(\(.*\))')
            for row_values in all_row_values:
                match = kernel_name_pattern.match(row_values[0])
                if match:
                    name = match.group(1) + match.group(2)
                else:
                    name = row_values[0]
                if len(name) > name_column_width:
                    row_values[0] = name[:name_column_width - 3] + '...'
                else:
                    row_values[0] = name
                append(row_format.format(*row_values))
            append(header_sep)
            append('')
            append('')
C
chenjian 已提交
1417

1418
    if views is None or SummaryView.MemoryManipulationView in views:
C
chenjian 已提交
1419

1420 1421 1422 1423 1424 1425 1426
        ###### Print Memory Manipulation Summary Report ######
        if statistic_data.event_summary.memory_manipulation_items:
            all_row_values = []
            memory_manipulation_items = statistic_data.event_summary.memory_manipulation_items
            gpu_total_time = statistic_data.event_summary.model_perspective_items[
                'ProfileStep'].general_gpu_time
            for name, item in memory_manipulation_items.items():
1427 1428 1429 1430
                if gpu_total_time == 0:
                    gpu_ratio = 0
                else:
                    gpu_ratio = float(item.general_gpu_time) / gpu_total_time
C
chenjian 已提交
1431 1432 1433 1434
                row_values = [
                    name,
                    item.call,
                    '{} / {} / {} / {} / {}'.format(
1435 1436 1437 1438
                        format_time(item.cpu_time, unit=time_unit),
                        format_time(item.avg_cpu_time, unit=time_unit),
                        format_time(item.max_cpu_time, unit=time_unit),
                        format_time(item.min_cpu_time, unit=time_unit),
C
chenjian 已提交
1439 1440
                        format_ratio(float(item.cpu_time) / total_time)),
                    '{} / {} / {} / {} / {}'.format(
1441 1442 1443 1444
                        format_time(item.general_gpu_time, unit=time_unit),
                        format_time(item.avg_general_gpu_time, unit=time_unit),
                        format_time(item.max_general_gpu_time, unit=time_unit),
                        format_time(item.min_general_gpu_time, unit=time_unit),
1445
                        format_ratio(gpu_ratio)),
C
chenjian 已提交
1446
                ]
C
chenjian 已提交
1447 1448
                all_row_values.append(row_values)

1449 1450 1451 1452 1453 1454 1455 1456 1457 1458 1459 1460 1461 1462 1463 1464 1465 1466 1467
            headers = [
                'Name', 'Calls', 'CPU Total / Avg / Max / Min / Ratio(%)',
                'GPU Total / Avg / Max / Min / Ratio(%)'
            ]
            # Calculate the column width
            name_column_width = 0
            calltime_width = 6
            cpu_data_description_width = 40
            gpu_data_description_width = 40
            for row_values in all_row_values:
                if len(row_values[0]) > name_column_width:
                    name_column_width = len(row_values[0])
                if isinstance(row_values[1],
                              int) and len(str(row_values[1])) > calltime_width:
                    calltime_width = len(str(row_values[1]))
                if len(row_values[2]) > cpu_data_description_width:
                    cpu_data_description_width = len(row_values[2])
                if len(row_values[3]) > gpu_data_description_width:
                    gpu_data_description_width = len(row_values[3])
C
chenjian 已提交
1468

1469 1470 1471 1472 1473 1474 1475
            row_format_list = [""]
            header_sep_list = [""]
            line_length_list = [-SPACING_SIZE]
            add_column(name_column_width)
            add_column(calltime_width)
            add_column(cpu_data_description_width)
            add_column(gpu_data_description_width)
C
chenjian 已提交
1476

1477 1478 1479
            row_format = row_format_list[0]
            header_sep = header_sep_list[0]
            line_length = line_length_list[0]
C
chenjian 已提交
1480

1481 1482 1483 1484 1485 1486 1487
            # construct table string
            append(add_title(line_length, "Memory Manipulation Summary"))
            append('Time unit: {}'.format(time_unit))
            append(header_sep)
            append(row_format.format(*headers))
            append(header_sep)
            for row_values in all_row_values:
C
chenjian 已提交
1488
                append(row_format.format(*row_values))
1489 1490 1491
            append(header_sep)
            append('')
            append('')
1492

1493
    if views is None or SummaryView.UDFView in views:
1494

1495 1496 1497 1498 1499 1500 1501 1502 1503 1504 1505 1506 1507 1508 1509 1510 1511 1512 1513 1514 1515 1516 1517 1518 1519 1520 1521 1522 1523 1524 1525 1526 1527 1528 1529 1530 1531 1532 1533 1534 1535 1536 1537 1538 1539 1540 1541 1542 1543 1544 1545 1546 1547 1548 1549 1550 1551 1552 1553 1554 1555 1556 1557 1558 1559 1560 1561 1562 1563 1564 1565 1566 1567
        ###### Print UserDefined Summary Report ######
        if statistic_data.event_summary.userdefined_items:
            all_row_values = []
            gpu_total_time = statistic_data.event_summary.model_perspective_items[
                'ProfileStep'].general_gpu_time
            if thread_sep == True:
                userdefined_thread_items = statistic_data.event_summary.userdefined_thread_items
            else:
                userdefined_thread_items = {
                    'All threads merged':
                    statistic_data.event_summary.userdefined_items
                }
            for thread_id, items in userdefined_thread_items.items():
                all_row_values.append("Thread: {}".format(thread_id))
                if sorted_by == SortedKeys.CPUTotal:
                    sorted_items = sorted(items.items(),
                                          key=lambda x: x[1].cpu_time,
                                          reverse=True)
                elif sorted_by == SortedKeys.CPUAvg:
                    sorted_items = sorted(items.items(),
                                          key=lambda x: x[1].avg_cpu_time,
                                          reverse=True)
                elif sorted_by == SortedKeys.CPUMax:
                    sorted_items = sorted(items.items(),
                                          key=lambda x: x[1].max_cpu_time,
                                          reverse=True)
                elif sorted_by == SortedKeys.CPUMin:
                    sorted_items = sorted(items.items(),
                                          key=lambda x: x[1].min_cpu_time)
                elif sorted_by == SortedKeys.GPUTotal:
                    sorted_items = sorted(items.items(),
                                          key=lambda x: x[1].general_gpu_time,
                                          reverse=True)
                elif sorted_by == SortedKeys.GPUAvg:
                    sorted_items = sorted(
                        items.items(),
                        key=lambda x: x[1].avg_general_gpu_time,
                        reverse=True)
                elif sorted_by == SortedKeys.GPUMax:
                    sorted_items = sorted(
                        items.items(),
                        key=lambda x: x[1].max_general_gpu_time,
                        reverse=True)
                elif sorted_by == SortedKeys.GPUMin:
                    sorted_items = sorted(
                        items.items(), key=lambda x: x[1].min_general_gpu_time)

                for name, item in sorted_items:
                    if gpu_total_time == 0:
                        gpu_ratio = 0
                    else:
                        gpu_ratio = float(
                            item.general_gpu_time) / gpu_total_time
                    row_values = [
                        name,
                        item.call,
                        '{} / {} / {} / {} / {}'.format(
                            format_time(item.cpu_time, unit=time_unit),
                            format_time(item.avg_cpu_time, unit=time_unit),
                            format_time(item.max_cpu_time, unit=time_unit),
                            format_time(item.min_cpu_time, unit=time_unit),
                            format_ratio(float(item.cpu_time) / total_time)),
                        '{} / {} / {} / {} / {}'.format(
                            format_time(item.general_gpu_time, unit=time_unit),
                            format_time(item.avg_general_gpu_time,
                                        unit=time_unit),
                            format_time(item.max_general_gpu_time,
                                        unit=time_unit),
                            format_time(item.min_general_gpu_time,
                                        unit=time_unit),
                            format_ratio(gpu_ratio)),
                    ]
                    all_row_values.append(row_values)
1568 1569

            # Calculate the column width
1570 1571 1572 1573 1574 1575 1576 1577 1578 1579 1580 1581 1582 1583 1584 1585 1586
            name_column_width = 0
            calltime_width = 6
            cpu_data_description_width = 40
            gpu_data_description_width = 40
            for row_values in all_row_values:
                if isinstance(row_values, str):
                    continue
                if len(row_values[0]) > name_column_width:
                    name_column_width = len(row_values[0])
                if isinstance(row_values[1],
                              int) and len(str(row_values[1])) > calltime_width:
                    calltime_width = len(str(row_values[1]))
                if len(row_values[2]) > cpu_data_description_width:
                    cpu_data_description_width = len(row_values[2])
                if len(row_values[3]) > gpu_data_description_width:
                    gpu_data_description_width = len(row_values[3])

1587
            headers = [
1588 1589
                'Name', 'Calls', 'CPU Total / Avg / Max / Min / Ratio(%)',
                'GPU Total / Avg / Max / Min / Ratio(%)'
1590 1591 1592 1593
            ]
            row_format_list = [""]
            header_sep_list = [""]
            line_length_list = [-SPACING_SIZE]
1594

1595
            add_column(name_column_width)
1596 1597 1598
            add_column(calltime_width)
            add_column(cpu_data_description_width)
            add_column(gpu_data_description_width)
1599 1600 1601 1602 1603 1604

            row_format = row_format_list[0]
            header_sep = header_sep_list[0]
            line_length = line_length_list[0]

            # construct table string
1605 1606
            append(add_title(line_length, "UserDefined Summary"))
            append('Time unit: {}'.format(time_unit))
1607 1608 1609 1610 1611 1612 1613 1614 1615 1616 1617
            append(header_sep)
            append(row_format.format(*headers))
            append(header_sep)
            for row_values in all_row_values:
                if isinstance(row_values, str):
                    append(add_title(line_length, row_values))
                else:
                    append(row_format.format(*row_values))
            append('')
            append('')

1618 1619 1620 1621 1622 1623 1624 1625 1626 1627 1628 1629 1630 1631 1632 1633 1634 1635 1636 1637 1638 1639 1640 1641 1642 1643 1644 1645 1646 1647 1648 1649 1650 1651 1652 1653 1654 1655 1656 1657 1658 1659 1660 1661 1662 1663 1664 1665 1666 1667 1668 1669 1670 1671 1672 1673 1674 1675 1676 1677 1678 1679 1680 1681 1682 1683 1684 1685 1686 1687 1688 1689 1690 1691 1692
    if views is None or SummaryView.MemoryView in views:

        ###### Print Memory Summary Report ######
        if statistic_data.memory_summary.allocated_items or statistic_data.memory_summary.reserved_items:
            for device_type, memory_events in statistic_data.memory_summary.allocated_items.items(
            ):
                all_row_values = []
                sorted_items = sorted(memory_events.items(),
                                      key=lambda x: x[1].increase_size,
                                      reverse=True)

                for event_name, item in sorted_items:
                    row_values = [
                        event_name, item.memory_type, item.allocation_count,
                        item.free_count, item.allocation_size, item.free_size,
                        item.increase_size
                    ]
                    all_row_values.append(row_values)

                sorted_reserved_items = sorted(
                    statistic_data.memory_summary.reserved_items[device_type].
                    items(),
                    key=lambda x: x[1].increase_size,
                    reverse=True)
                for event_name, item in sorted_reserved_items:
                    row_values = [
                        event_name, item.memory_type, item.allocation_count,
                        item.free_count, item.allocation_size, item.free_size,
                        item.increase_size
                    ]
                    all_row_values.append(row_values)

                # Calculate the column width
                headers = [
                    'Name', 'Type', 'Allocation Count', 'Free Count',
                    'Allocation Size', 'Free Size', 'Increased Size'
                ]
                row_format_list = [""]
                header_sep_list = [""]
                line_length_list = [-SPACING_SIZE]
                name_column_width = 50
                number_column_width = 15
                add_column(name_column_width)
                add_column(12)
                add_column(number_column_width)
                add_column(number_column_width)
                add_column(number_column_width)
                add_column(number_column_width)
                add_column(number_column_width)

                row_format = row_format_list[0]
                header_sep = header_sep_list[0]
                line_length = line_length_list[0]

                # construct table string
                append(
                    add_title(line_length,
                              "Memory Summary - {}".format(device_type)))
                append('Peak Allocated Memory: {}'.format(
                    statistic_data.memory_summary.
                    peak_allocation_values[device_type]))
                append('Peak Reserved Memory: {}'.format(
                    statistic_data.memory_summary.
                    peak_reserved_values[device_type]))
                append(header_sep)
                append(row_format.format(*headers))
                append(header_sep)
                for row_values in all_row_values:
                    if isinstance(row_values, str):
                        append(add_title(line_length, row_values))
                    else:
                        append(row_format.format(*row_values))
                append('')
                append('')

C
chenjian 已提交
1693
    return ''.join(result)