profiler.cc 30.8 KB
Newer Older
1
/* Copyright (c) 2016 PaddlePaddle Authors. All Rights Reserved.
D
dangqingqing 已提交
2 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
6

D
dangqingqing 已提交
7 8 9 10 11 12 13 14
    http://www.apache.org/licenses/LICENSE-2.0

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
#include "paddle/fluid/platform/profiler.h"

17
#include <mutex>  // NOLINT
18
#include <random>
L
liutiexing 已提交
19
#include <sstream>
20
#include <string>
L
liutiexing 已提交
21
#include <type_traits>
Y
Yancey1989 已提交
22

23
#include "paddle/fluid/platform/device_tracer.h"
W
wangchaochaohu 已提交
24
#include "paddle/fluid/platform/enforce.h"
25
#include "paddle/fluid/platform/profiler/common_event.h"
L
liutiexing 已提交
26
#include "paddle/fluid/platform/profiler/host_event_recorder.h"
27
#include "paddle/fluid/platform/profiler/host_tracer.h"
C
chenjian 已提交
28
#include "paddle/fluid/platform/profiler/profiler.h"
W
wangchaochaohu 已提交
29
#include "paddle/fluid/platform/profiler_helper.h"
30 31 32
#ifdef PADDLE_WITH_CUDA
#include "paddle/fluid/platform/dynload/nvtx.h"
#endif
33 34
#include "paddle/fluid/framework/op_proto_maker.h"
#include "paddle/fluid/framework/operator.h"
35
#include "paddle/fluid/platform/os_info.h"
D
dangqingqing 已提交
36

37 38
PADDLE_DEFINE_EXPORTED_bool(enable_rpc_profiler,
                            false,
Z
Zeng Jinle 已提交
39
                            "Enable rpc profiler or not.");
G
gongweibao 已提交
40

41 42
DEFINE_bool(enable_host_event_recorder_hook,
            false,
43 44
            "enable HostEventRecorder, hook Profiler");

D
dangqingqing 已提交
45 46 47
namespace paddle {
namespace platform {

W
wangchaochaohu 已提交
48
MemEvenRecorder MemEvenRecorder::recorder;
D
dangqingqing 已提交
49

50 51 52 53 54
Event::Event(EventType type,
             std::string name,
             uint32_t thread_id,
             EventRole role,
             std::string attr)
Y
Yuang Liu 已提交
55 56 57 58 59
    : type_(type),
      name_(name),
      thread_id_(thread_id),
      role_(role),
      attr_(attr) {
D
dangqingqing 已提交
60 61 62
  cpu_ns_ = GetTimeInNsec();
}

C
chengduo 已提交
63
const EventType &Event::type() const { return type_; }
D
dangqingqing 已提交
64

C
chengduo 已提交
65
double Event::CpuElapsedMs(const Event &e) const {
66
  return (e.cpu_ns_ - cpu_ns_) / (1000000.0);
D
dangqingqing 已提交
67 68
}

C
chengduo 已提交
69
double Event::CudaElapsedMs(const Event &e) const {
70 71
#ifdef PADDLE_WITH_CUPTI
  return gpu_ns_ / 1000000.0;
D
Dun Liang 已提交
72
#else
D
Dun Liang 已提交
73 74
  LOG_FIRST_N(WARNING, 1) << "CUDA CUPTI is not enabled";
  return 0;
D
dangqingqing 已提交
75 76 77
#endif
}

78 79 80 81
RecordEvent::RecordEvent(const char *name,
                         const TracerEventType type,
                         uint32_t level,
                         const EventRole role) {
L
liutiexing 已提交
82 83 84 85 86 87 88 89
#ifndef _WIN32
#ifdef PADDLE_WITH_CUDA
  if (g_enable_nvprof_hook) {
    dynload::nvtxRangePushA(name);
    is_pushed_ = true;
  }
#endif
#endif
C
chenjian 已提交
90 91 92 93
  if (UNLIKELY(HostTraceLevel::GetInstance().NeedTrace(level) == false)) {
    return;
  }

94
  if (FLAGS_enable_host_event_recorder_hook == false) {
L
liutiexing 已提交
95
    if (g_state != ProfilerState::kDisabled) {  // avoid temp string
C
chenjian 已提交
96 97 98 99 100
      if (type == TracerEventType::Operator ||
          type == TracerEventType::OperatorInner ||
          type == TracerEventType::UserDefined) {
        OriginalConstruct(name, role, "none");
      }
L
liutiexing 已提交
101
    }
L
liutiexing 已提交
102 103
    return;
  }
C
chenjian 已提交
104

105
  is_enabled_ = true;
L
liutiexing 已提交
106 107
  shallow_copy_name_ = name;
  role_ = role;
C
chenjian 已提交
108
  type_ = type;
L
liutiexing 已提交
109 110 111
  start_ns_ = PosixInNsec();
}

112 113 114 115
RecordEvent::RecordEvent(const std::string &name,
                         const TracerEventType type,
                         uint32_t level,
                         const EventRole role) {
L
liutiexing 已提交
116 117 118 119 120 121 122 123
#ifndef _WIN32
#ifdef PADDLE_WITH_CUDA
  if (g_enable_nvprof_hook) {
    dynload::nvtxRangePushA(name.c_str());
    is_pushed_ = true;
  }
#endif
#endif
C
chenjian 已提交
124
  if (UNLIKELY(HostTraceLevel::GetInstance().NeedTrace(level) == false)) {
L
liutiexing 已提交
125 126
    return;
  }
C
chenjian 已提交
127 128 129 130 131 132 133

  if (FLAGS_enable_host_event_recorder_hook == false) {
    if (type == TracerEventType::Operator ||
        type == TracerEventType::OperatorInner ||
        type == TracerEventType::UserDefined) {
      OriginalConstruct(name, role, "none");
    }
134 135
    return;
  }
C
chenjian 已提交
136

137
  is_enabled_ = true;
L
liutiexing 已提交
138 139
  name_ = new std::string(name);
  role_ = role;
C
chenjian 已提交
140
  type_ = type;
L
liutiexing 已提交
141 142 143
  start_ns_ = PosixInNsec();
}

144 145 146 147
RecordEvent::RecordEvent(const std::string &name,
                         const std::string &attr,
                         const TracerEventType type,
                         uint32_t level,
C
chenjian 已提交
148
                         const EventRole role) {
149 150 151 152 153 154 155 156
#ifndef _WIN32
#ifdef PADDLE_WITH_CUDA
  if (g_enable_nvprof_hook) {
    dynload::nvtxRangePushA(name.c_str());
    is_pushed_ = true;
  }
#endif
#endif
C
chenjian 已提交
157 158

  if (UNLIKELY(HostTraceLevel::GetInstance().NeedTrace(level) == false)) {
L
liutiexing 已提交
159 160
    return;
  }
C
chenjian 已提交
161 162 163 164 165 166 167

  if (FLAGS_enable_host_event_recorder_hook == false) {
    if (type == TracerEventType::Operator ||
        type == TracerEventType::OperatorInner ||
        type == TracerEventType::UserDefined) {
      OriginalConstruct(name, role, attr);
    }
168 169
    return;
  }
C
chenjian 已提交
170

171
  is_enabled_ = true;
C
chenjian 已提交
172
  type_ = type;
L
liutiexing 已提交
173 174 175 176
  name_ = new std::string(name);
  start_ns_ = PosixInNsec();
  attr_ = new std::string(attr);
}
L
liutiexing 已提交
177

L
liutiexing 已提交
178 179 180
void RecordEvent::OriginalConstruct(const std::string &name,
                                    const EventRole role,
                                    const std::string &attr) {
181
  if (g_state == ProfilerState::kDisabled || name.empty()) return;
182 183

  // do some initialization
L
liutiexing 已提交
184
  name_ = new std::string(name);
185 186
  start_ns_ = PosixInNsec();
  role_ = role;
L
liutiexing 已提交
187
  attr_ = new std::string(attr);
X
Xin Pan 已提交
188
  is_enabled_ = true;
189
  // lock is not needed, the code below is thread-safe
190
  // Maybe need the same push/pop behavior.
Y
Yuang Liu 已提交
191
  Event *e = PushEvent(name, role, attr);
192
  SetCurAnnotation(e);
L
liutiexing 已提交
193
  *name_ = e->name();
D
dangqingqing 已提交
194 195
}

L
liutiexing 已提交
196
void RecordEvent::End() {
197 198
#ifndef _WIN32
#ifdef PADDLE_WITH_CUDA
199
  if (g_enable_nvprof_hook && is_pushed_) {
200
    dynload::nvtxRangePop();
201
    is_pushed_ = false;
202 203 204
  }
#endif
#endif
205
  if (LIKELY(FLAGS_enable_host_event_recorder_hook && is_enabled_)) {
L
liutiexing 已提交
206
    uint64_t end_ns = PosixInNsec();
L
liutiexing 已提交
207
    if (LIKELY(shallow_copy_name_ != nullptr)) {
L
liutiexing 已提交
208
      HostEventRecorder<CommonEvent>::GetInstance().RecordEvent(
C
chenjian 已提交
209
          shallow_copy_name_, start_ns_, end_ns, role_, type_);
L
liutiexing 已提交
210 211
    } else if (name_ != nullptr) {
      if (attr_ == nullptr) {
L
liutiexing 已提交
212 213
        HostEventRecorder<CommonEvent>::GetInstance().RecordEvent(
            *name_, start_ns_, end_ns, role_, type_);
L
liutiexing 已提交
214
      } else {
L
liutiexing 已提交
215 216
        HostEventRecorder<CommonEvent>::GetInstance().RecordEvent(
            *name_, start_ns_, end_ns, role_, type_, *attr_);
L
liutiexing 已提交
217
        delete attr_;
L
liutiexing 已提交
218
      }
L
liutiexing 已提交
219
      delete name_;
L
liutiexing 已提交
220
    }
221 222
    // use this flag to avoid double End();
    is_enabled_ = false;
L
liutiexing 已提交
223 224 225
    return;
  }

X
Xin Pan 已提交
226
  if (g_state == ProfilerState::kDisabled || !is_enabled_) return;
227
  // lock is not needed, the code below is thread-safe
C
chengduo 已提交
228
  DeviceTracer *tracer = GetDeviceTracer();
X
Xin Pan 已提交
229
  if (tracer) {
L
liutiexing 已提交
230
    uint64_t end_ns = PosixInNsec();
231 232
    tracer->AddCPURecords(
        CurAnnotationName(), start_ns_, end_ns, BlockDepth(), g_thread_id);
X
Xin Pan 已提交
233
  }
Y
Yibing Liu 已提交
234
  ClearCurAnnotation();
L
liutiexing 已提交
235 236 237
  PopEvent(*name_, role_);
  delete name_;
  delete attr_;
238 239
  // use this flag to avoid double End();
  is_enabled_ = false;
D
dangqingqing 已提交
240
}
D
dangqingqing 已提交
241

242 243
RecordInstantEvent::RecordInstantEvent(const char *name,
                                       TracerEventType type,
244 245
                                       uint32_t level) {
  if (UNLIKELY(HostTraceLevel::GetInstance().NeedTrace(level) == false)) {
L
liutiexing 已提交
246 247 248
    return;
  }
  auto start_end_ns = PosixInNsec();
L
liutiexing 已提交
249 250
  HostEventRecorder<CommonEvent>::GetInstance().RecordEvent(
      name, start_end_ns, start_end_ns, EventRole::kOrdinary, type);
L
liutiexing 已提交
251 252
}

253 254 255 256 257 258 259 260 261 262 263 264 265 266 267 268 269 270 271 272 273 274 275 276 277 278 279
RecordOpInfoSupplement::RecordOpInfoSupplement(
    const std::string &type,
    const framework::AttributeMap &attrs,
    const framework::InferShapeContext &shape_ctx,
    const framework::RuntimeContext &ctx) {
  if (FLAGS_enable_host_event_recorder_hook == false) {
    return;
  }
  std::map<std::string, std::vector<framework::DDim>> input_shapes;
  std::map<std::string, std::vector<framework::proto::VarType::Type>> dtypes;
  for (auto it = ctx.inputs.begin(); it != ctx.inputs.end(); it++) {
    input_shapes[it->first] = shape_ctx.GetInputsDim(it->first);
    dtypes[it->first] = shape_ctx.GetInputsVarType(it->first);
  }

  const std::vector<std::string> *callstack_ptr = nullptr;
  std::vector<std::string> callstack;
  auto iter = attrs.find(
      framework::OpProtoAndCheckerMaker::OpCreationCallstackAttrName());
  if (iter != attrs.end()) {
    callstack_ptr = &BOOST_GET_CONST(std::vector<std::string>, iter->second);
    callstack = *callstack_ptr;
  }
  HostEventRecorder<OperatorSupplementOriginEvent>::GetInstance().RecordEvent(
      PosixInNsec(), type, input_shapes, dtypes, callstack);
}

C
chenjian 已提交
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
RecordOpInfoSupplement::RecordOpInfoSupplement(
    const std::string &type,
    const framework::AttributeMap &attrs,
    const framework::InferShapeContext &shape_ctx,
    const phi::KernelSignature &kernel_signature) {
  if (FLAGS_enable_host_event_recorder_hook == false) {
    return;
  }
  std::map<std::string, std::vector<framework::DDim>> input_shapes;
  std::map<std::string, std::vector<framework::proto::VarType::Type>> dtypes;
  for (auto it = kernel_signature.input_names.begin();
       it != kernel_signature.input_names.end();
       it++) {
    std::string input_name(*it);
    if (shape_ctx.HasInputs(input_name)) {
      input_shapes[input_name] = shape_ctx.GetInputsDim(input_name);
      dtypes[input_name] = shape_ctx.GetInputsVarType(input_name);
    }
  }
  const std::vector<std::string> *callstack_ptr = nullptr;
  std::vector<std::string> callstack;
  auto iter = attrs.find(
      framework::OpProtoAndCheckerMaker::OpCreationCallstackAttrName());
  if (iter != attrs.end()) {
    callstack_ptr = &BOOST_GET_CONST(std::vector<std::string>, iter->second);
    callstack = *callstack_ptr;
  }
  HostEventRecorder<OperatorSupplementOriginEvent>::GetInstance().RecordEvent(
      PosixInNsec(), type, input_shapes, dtypes, callstack);
}

311 312 313 314 315 316 317 318 319 320 321 322 323 324 325 326 327 328 329 330 331 332 333 334 335 336 337 338 339 340 341 342 343 344 345 346 347 348 349 350 351 352 353 354 355 356 357 358 359 360 361 362 363 364 365 366 367 368 369 370 371 372 373 374 375 376 377 378 379 380 381 382 383 384 385 386 387 388 389 390 391 392 393 394 395 396 397 398 399 400 401 402 403 404 405 406 407 408 409 410 411 412 413 414 415 416 417 418 419 420 421 422 423 424 425 426 427
RecordMemEvent::RecordMemEvent(const void *ptr,
                               const phi::Place &place,
                               size_t size,
                               const TracerMemEventType type) {
  if (g_state == ProfilerState::kDisabled &&
      FLAGS_enable_host_event_recorder_hook == false) {
    return;
  }
  if (type == TracerMemEventType::Allocate) {
    uint64_t current_allocated;
    uint64_t peak_allocated;
    uint64_t current_reserved = 0;  // 0 means keep the same as before
    uint64_t peak_reserved = 0;     // 0 means keep the same as before
    if (platform::is_cpu_place(place) ||
        platform::is_cuda_pinned_place(place)) {
      current_allocated =
          HOST_MEMORY_STAT_CURRENT_VALUE(Allocated, place.GetDeviceId());
      peak_allocated =
          HOST_MEMORY_STAT_PEAK_VALUE(Allocated, place.GetDeviceId());
    } else {
      current_allocated =
          DEVICE_MEMORY_STAT_CURRENT_VALUE(Allocated, place.GetDeviceId());
      peak_allocated =
          DEVICE_MEMORY_STAT_PEAK_VALUE(Allocated, place.GetDeviceId());
    }

    platform::MemEvenRecorder::Instance().PushMemRecord(ptr,
                                                        place,
                                                        size,
                                                        type,
                                                        current_allocated,
                                                        current_reserved,
                                                        peak_allocated,
                                                        peak_reserved);
  } else if (type == TracerMemEventType::ReservedAllocate) {
    uint64_t current_reserved;
    uint64_t peak_reserved;
    uint64_t current_allocated = 0;  // 0 means keep the same as before
    uint64_t peak_allocated = 0;     // 0 means keep the same as before
    if (platform::is_cpu_place(place) ||
        platform::is_cuda_pinned_place(place)) {
      current_reserved =
          HOST_MEMORY_STAT_CURRENT_VALUE(Reserved, place.GetDeviceId());
      peak_reserved =
          HOST_MEMORY_STAT_PEAK_VALUE(Reserved, place.GetDeviceId());
    } else {
      current_reserved =
          DEVICE_MEMORY_STAT_CURRENT_VALUE(Reserved, place.GetDeviceId());
      peak_reserved =
          DEVICE_MEMORY_STAT_PEAK_VALUE(Reserved, place.GetDeviceId());
    }

    platform::MemEvenRecorder::Instance().PushMemRecord(ptr,
                                                        place,
                                                        size,
                                                        type,
                                                        current_allocated,
                                                        current_reserved,
                                                        peak_allocated,
                                                        peak_reserved);
  } else if (type == TracerMemEventType::Free) {
    uint64_t current_allocated;
    uint64_t peak_allocated;
    uint64_t current_reserved = 0;  // 0 means keep the same as before
    uint64_t peak_reserved = 0;     // 0 means keep the same as before
    if (platform::is_cpu_place(place) ||
        platform::is_cuda_pinned_place(place)) {
      current_allocated =
          HOST_MEMORY_STAT_CURRENT_VALUE(Allocated, place.GetDeviceId());
      peak_allocated =
          HOST_MEMORY_STAT_PEAK_VALUE(Allocated, place.GetDeviceId());
    } else {
      current_allocated =
          DEVICE_MEMORY_STAT_CURRENT_VALUE(Allocated, place.GetDeviceId());
      peak_allocated =
          DEVICE_MEMORY_STAT_PEAK_VALUE(Allocated, place.GetDeviceId());
    }

    platform::MemEvenRecorder::Instance().PopMemRecord(ptr,
                                                       place,
                                                       size,
                                                       type,
                                                       current_allocated,
                                                       current_reserved,
                                                       peak_allocated,
                                                       peak_reserved);
  } else if (type == TracerMemEventType::ReservedFree) {
    uint64_t current_reserved;
    uint64_t peak_reserved;
    uint64_t current_allocated = 0;  // 0 means keep the same as before
    uint64_t peak_allocated = 0;     // 0 means keep the same as before
    if (platform::is_cpu_place(place) ||
        platform::is_cuda_pinned_place(place)) {
      current_reserved =
          HOST_MEMORY_STAT_CURRENT_VALUE(Reserved, place.GetDeviceId());
      peak_reserved =
          HOST_MEMORY_STAT_PEAK_VALUE(Reserved, place.GetDeviceId());
    } else {
      current_reserved =
          DEVICE_MEMORY_STAT_CURRENT_VALUE(Reserved, place.GetDeviceId());
      peak_reserved =
          DEVICE_MEMORY_STAT_PEAK_VALUE(Reserved, place.GetDeviceId());
    }

    platform::MemEvenRecorder::Instance().PopMemRecord(ptr,
                                                       place,
                                                       size,
                                                       type,
                                                       current_allocated,
                                                       current_reserved,
                                                       peak_allocated,
                                                       peak_reserved);
  }
}

void MemEvenRecorder::PushMemRecord(const void *ptr,
                                    const Place &place,
C
chengduo 已提交
428
                                    size_t size) {
429 430 431
  if (g_state == ProfilerState::kDisabled) {
    return;
  }
C
chengduo 已提交
432 433
  std::lock_guard<std::mutex> guard(mtx_);
  auto &events = address_memevent_[place];
434 435
  PADDLE_ENFORCE_EQ(events.count(ptr),
                    0,
G
GaoWei8 已提交
436 437
                    platform::errors::InvalidArgument(
                        "The Place can't exist in the stage of PushMemRecord"));
438 439 440 441 442 443 444 445 446 447 448 449 450 451 452 453 454 455 456 457 458 459 460 461 462 463 464 465 466 467 468 469 470 471 472 473 474 475 476 477
  events.emplace(ptr,
                 std::unique_ptr<RecordMemEvent>(
                     new MemEvenRecorder::RecordMemEvent(place, size)));
}

void MemEvenRecorder::PushMemRecord(const void *ptr,
                                    const Place &place,
                                    size_t size,
                                    TracerMemEventType type,
                                    uint64_t current_allocated,
                                    uint64_t current_reserved,
                                    uint64_t peak_allocated,
                                    uint64_t peak_reserved) {
  std::lock_guard<std::mutex> guard(mtx_);
  if (FLAGS_enable_host_event_recorder_hook) {  // new MemRecord
    HostEventRecorder<CommonMemEvent>::GetInstance().RecordEvent(
        PosixInNsec(),
        reinterpret_cast<uint64_t>(ptr),
        type,
        size,
        place,
        current_allocated,
        current_reserved,
        peak_allocated,
        peak_reserved);
    return;
  }
  if (type == TracerMemEventType::ReservedAllocate) {
    // old profiler only analyse memory managed by paddle.
    return;
  }
  if (g_state == ProfilerState::kDisabled) return;
  auto &events = address_memevent_[place];
  PADDLE_ENFORCE_EQ(events.count(ptr),
                    0,
                    platform::errors::InvalidArgument(
                        "The Place can't exist in the stage of PushMemRecord"));
  events.emplace(ptr,
                 std::unique_ptr<RecordMemEvent>(
                     new MemEvenRecorder::RecordMemEvent(place, size)));
C
chengduo 已提交
478 479 480
}

void MemEvenRecorder::PopMemRecord(const void *ptr, const Place &place) {
481 482 483
  if (g_state == ProfilerState::kDisabled) {
    return;
  }
C
chengduo 已提交
484 485 486 487 488 489 490 491 492
  std::lock_guard<std::mutex> guard(mtx_);
  auto &events = address_memevent_[place];
  auto iter = events.find(ptr);
  // The ptr maybe not in address_memevent
  if (iter != events.end()) {
    events.erase(iter);
  }
}

493 494 495 496 497 498 499 500 501 502 503 504 505 506 507 508 509 510 511 512 513 514 515 516 517 518 519 520 521 522 523 524 525 526 527
void MemEvenRecorder::PopMemRecord(const void *ptr,
                                   const Place &place,
                                   size_t size,
                                   TracerMemEventType type,
                                   uint64_t current_allocated,
                                   uint64_t current_reserved,
                                   uint64_t peak_allocated,
                                   uint64_t peak_reserved) {
  std::lock_guard<std::mutex> guard(mtx_);
  if (FLAGS_enable_host_event_recorder_hook) {  // new MemRecord
    HostEventRecorder<CommonMemEvent>::GetInstance().RecordEvent(
        PosixInNsec(),
        reinterpret_cast<uint64_t>(ptr),
        type,
        -size,
        place,
        current_allocated,
        current_reserved,
        peak_allocated,
        peak_reserved);
    return;
  }
  if (type == TracerMemEventType::ReservedFree) {
    // old profiler only analyse memory managed by paddle.
    return;
  }
  if (g_state == ProfilerState::kDisabled) return;
  auto &events = address_memevent_[place];
  auto iter = events.find(ptr);
  // The ptr maybe not in address_memevent
  if (iter != events.end()) {
    events.erase(iter);
  }
}

C
chengduo 已提交
528 529 530 531 532 533 534 535 536 537 538 539 540 541 542 543 544 545 546 547
void MemEvenRecorder::Flush() {
  std::lock_guard<std::mutex> guard(mtx_);
  address_memevent_.clear();
}

MemEvenRecorder::RecordMemEvent::RecordMemEvent(const Place &place,
                                                size_t bytes)
    : place_(place),
      bytes_(bytes),
      start_ns_(PosixInNsec()),
      alloc_in_(CurAnnotationName()) {
  PushMemEvent(start_ns_, end_ns_, bytes_, place_, alloc_in_);
}

MemEvenRecorder::RecordMemEvent::~RecordMemEvent() {
  DeviceTracer *tracer = GetDeviceTracer();
  end_ns_ = PosixInNsec();

  auto annotation_free = CurAnnotationName();
  if (tracer) {
548 549 550 551 552 553 554
    tracer->AddMemInfoRecord(start_ns_,
                             end_ns_,
                             bytes_,
                             place_,
                             alloc_in_,
                             annotation_free,
                             g_mem_thread_id);
C
chengduo 已提交
555 556 557 558
  }
  PopMemEvent(start_ns_, end_ns_, bytes_, place_, annotation_free);
}

L
liutiexing 已提交
559
/*RecordRPCEvent::RecordRPCEvent(const std::string &name) {
G
gongweibao 已提交
560
  if (FLAGS_enable_rpc_profiler) {
561
    event_.reset(new platform::RecordEvent(name));
G
gongweibao 已提交
562
  }
L
liutiexing 已提交
563
}*/
G
gongweibao 已提交
564

X
Xin Pan 已提交
565 566
RecordBlock::RecordBlock(int block_id)
    : is_enabled_(false), start_ns_(PosixInNsec()) {
567
  // lock is not needed, the code below is thread-safe
X
Xin Pan 已提交
568
  if (g_state == ProfilerState::kDisabled) return;
X
Xin Pan 已提交
569
  is_enabled_ = true;
X
Xin Pan 已提交
570 571 572 573 574
  SetCurBlock(block_id);
  name_ = string::Sprintf("block_%d", block_id);
}

RecordBlock::~RecordBlock() {
575
  // lock is not needed, the code below is thread-safe
X
Xin Pan 已提交
576
  if (g_state == ProfilerState::kDisabled || !is_enabled_) return;
C
chengduo 已提交
577
  DeviceTracer *tracer = GetDeviceTracer();
X
Xin Pan 已提交
578 579 580
  if (tracer) {
    // We try to put all blocks at the same nested depth in the
    // same timeline lane. and distinguish the using thread_id.
581 582
    tracer->AddCPURecords(
        name_, start_ns_, PosixInNsec(), BlockDepth(), g_thread_id);
X
Xin Pan 已提交
583 584 585 586
  }
  ClearCurBlock();
}

587 588 589 590 591 592 593 594 595 596 597 598 599 600 601 602 603 604 605 606 607 608 609 610 611 612
void PushMemEvent(uint64_t start_ns,
                  uint64_t end_ns,
                  size_t bytes,
                  const Place &place,
                  const std::string &annotation) {
  GetMemEventList().Record(EventType::kPushRange,
                           start_ns,
                           end_ns,
                           bytes,
                           place,
                           g_mem_thread_id,
                           annotation);
}

void PopMemEvent(uint64_t start_ns,
                 uint64_t end_ns,
                 size_t bytes,
                 const Place &place,
                 const std::string &annotation) {
  GetMemEventList().Record(EventType::kPopRange,
                           start_ns,
                           end_ns,
                           bytes,
                           place,
                           g_mem_thread_id,
                           annotation);
W
wangchaochaohu 已提交
613 614 615
}

void Mark(const std::string &name) {
616
  if (FLAGS_enable_host_event_recorder_hook) {
L
liutiexing 已提交
617
    HostEventRecorder<CommonEvent>::GetInstance().RecordEvent(
C
chenjian 已提交
618
        name, 0, 0, EventRole::kOrdinary, TracerEventType::UserDefined);
619 620
    return;
  }
W
wangchaochaohu 已提交
621 622 623
  GetEventList().Record(EventType::kMark, name, g_thread_id);
}

624 625
Event *PushEvent(const std::string &name,
                 const EventRole role,
Y
Yuang Liu 已提交
626
                 std::string attr) {
627 628
  return GetEventList().Record(
      EventType::kPushRange, name, g_thread_id, role, attr);
629 630
}

Y
Yuang Liu 已提交
631 632
void PopEvent(const std::string &name, const EventRole role, std::string attr) {
  GetEventList().Record(EventType::kPopRange, name, g_thread_id, role, attr);
W
wangchaochaohu 已提交
633
}
D
dangqingqing 已提交
634
void EnableProfiler(ProfilerState state) {
635 636
  PADDLE_ENFORCE_NE(state,
                    ProfilerState::kDisabled,
W
wangchaochaohu 已提交
637 638 639
                    platform::errors::InvalidArgument(
                        "Can't enable profiling, since the input state is"
                        "ProfilerState::kDisabled"));
640
  SynchronizeAllDevice();
X
Xin Pan 已提交
641
  std::lock_guard<std::mutex> l(profiler_mu);
642 643
  if (state == g_state) {
    return;
644
  }
645
  g_state = state;
C
chenjian 已提交
646 647
  ProfilerOptions option;
  HostTraceLevel::GetInstance().SetLevel(option.trace_level);
X
Xin Pan 已提交
648
  should_send_profile_state = true;
649
  GetDeviceTracer()->Enable();
650
#if defined(PADDLE_WITH_CUDA) || defined(PADDLE_WITH_HIP)
651 652
  if (g_state == ProfilerState::kCUDA || g_state == ProfilerState::kAll ||
      g_state == ProfilerState::kCPU) {
653
    // Generate some dummy events first to reduce the startup overhead.
654 655
    DummyKernelAndEvent();
    GetDeviceTracer()->Reset();
D
dangqingqing 已提交
656 657 658
  }
#endif
  // Mark the profiling start.
659
  Mark("_start_profiler_");
D
dangqingqing 已提交
660 661
}

662
void ResetProfiler() {
663 664
  SynchronizeAllDevice();
  GetDeviceTracer()->Reset();
C
chengduo 已提交
665
  MemEvenRecorder::Instance().Flush();
D
dangqingqing 已提交
666
  std::lock_guard<std::mutex> guard(g_all_event_lists_mutex);
667 668 669 670
  for (auto it = g_all_event_lists.begin(); it != g_all_event_lists.end();
       ++it) {
    (*it)->Clear();
  }
C
chengduo 已提交
671
  for (auto it = g_all_mem_event_lists.begin();
672 673
       it != g_all_mem_event_lists.end();
       ++it) {
C
chengduo 已提交
674 675
    (*it)->Clear();
  }
676 677
}

678 679 680 681
static std::map<uint64_t, ThreadEvents> DockHostEventRecorderHostPart();
static void DockHostEventRecorderDevicePart(
    const std::map<uint64_t, ThreadEvents> &thr_events);

682
void DisableProfiler(EventSortingKey sorted_key,
C
chengduo 已提交
683
                     const std::string &profile_path) {
684
  SynchronizeAllDevice();
685
  auto thr_events = DockHostEventRecorderHostPart();
C
chengduo 已提交
686 687
  MemEvenRecorder::Instance().Flush();

X
Xin Pan 已提交
688
  std::lock_guard<std::mutex> l(profiler_mu);
689
  if (g_state == ProfilerState::kDisabled) return;
690
  // Mark the profiling stop.
691
  Mark("_stop_profiler_");
692
  DealWithShowName();
693

C
chengduo 已提交
694
  DeviceTracer *tracer = GetDeviceTracer();
695
  if (tracer->IsEnabled()) {
696
    tracer->Disable();
697
    DockHostEventRecorderDevicePart(thr_events);
698
    tracer->GenEventKernelCudaElapsedTime();
699
    tracer->GenProfile(profile_path);
700
  }
701 702

  std::vector<std::vector<Event>> all_events = GetAllEvents();
703

704 705
  ParseEvents(all_events, true, sorted_key);
  ParseEvents(all_events, false, sorted_key);
H
Huihuang Zheng 已提交
706 707 708 709 710 711 712 713 714 715 716 717 718 719

  std::vector<std::vector<MemEvent>> all_mem_events = GetMemEvents();
  ParseMemEvents(all_mem_events);

  ResetProfiler();
  g_state = ProfilerState::kDisabled;
  g_tracer_option = TracerOption::kDefault;
  should_send_profile_state = true;
}

void CompleteProfilerEvents(proto::Profile *tracer_profile,
                            std::vector<std::vector<Event>> *time_events,
                            std::vector<std::vector<MemEvent>> *mem_events) {
  SynchronizeAllDevice();
720
  auto thr_events = DockHostEventRecorderHostPart();
H
Huihuang Zheng 已提交
721 722 723 724 725 726 727 728 729 730 731
  MemEvenRecorder::Instance().Flush();

  std::lock_guard<std::mutex> l(profiler_mu);
  if (g_state == ProfilerState::kDisabled) return;

  // Mark the profiling stop.
  Mark("_stop_profiler_");

  DeviceTracer *tracer = GetDeviceTracer();
  if (tracer->IsEnabled() && tracer_profile != nullptr) {
    tracer->Disable();
732
    DockHostEventRecorderDevicePart(thr_events);
H
Huihuang Zheng 已提交
733 734 735 736 737 738 739 740 741
    tracer->GenEventKernelCudaElapsedTime();
    *tracer_profile = tracer->GetProfile();
  }

  if (time_events != nullptr) {
    *time_events = GetAllEvents();
  }
  if (mem_events != nullptr) {
    *mem_events = GetMemEvents();
C
chengduo 已提交
742 743
  }

744
  ResetProfiler();
745
  g_state = ProfilerState::kDisabled;
746
  g_tracer_option = TracerOption::kDefault;
X
Xin Pan 已提交
747
  should_send_profile_state = true;
748 749
}

W
wangchaochaohu 已提交
750 751 752 753 754 755 756 757 758 759
std::vector<std::vector<Event>> GetAllEvents() {
  std::lock_guard<std::mutex> guard(g_all_event_lists_mutex);
  std::vector<std::vector<Event>> result;
  for (auto it = g_all_event_lists.begin(); it != g_all_event_lists.end();
       ++it) {
    result.emplace_back((*it)->Reduce());
  }
  return result;
}

760 761
bool IsProfileEnabled() { return g_state != ProfilerState::kDisabled; }

W
wangchaochaohu 已提交
762
bool ShouldSendProfileState() { return should_send_profile_state; }
763

764 765
std::string OpName(const framework::VariableNameMap &name_map,
                   const std::string &type_name) {
766 767
  if (platform::GetTracerOption() != platform::TracerOption::kAllOpDetail ||
      !IsProfileEnabled())
768 769 770 771 772
    return "";

  std::string ret = type_name + "%";
  for (auto it = name_map.begin(); it != name_map.end(); it++) {
    auto name_outputs = it->second;
773
    if (!name_outputs.empty()) {
774 775 776 777 778 779 780 781 782 783 784 785 786 787 788
      ret = ret + name_outputs[0];
      break;
    }
  }
  ret = ret + "%";

  return ret;
}

void SetTracerOption(TracerOption option) {
  std::lock_guard<std::mutex> l(profiler_mu);
  g_tracer_option = option;
}

platform::TracerOption GetTracerOption() { return g_tracer_option; }
W
wangchaochaohu 已提交
789 790 791 792 793 794 795 796 797 798 799

void SetProfileListener() {
  std::mt19937 rng;
  rng.seed(std::random_device()());
  std::uniform_int_distribution<std::mt19937::result_type> dist6(
      1, std::numeric_limits<int>::max());
  profiler_lister_id = dist6(rng);
}

int64_t ListenerId() { return profiler_lister_id; }

800 801 802 803 804 805 806
void NvprofEnableRecordEvent() {
  SynchronizeAllDevice();
  g_enable_nvprof_hook = true;
}

void NvprofDisableRecordEvent() { g_enable_nvprof_hook = false; }

807
void EnableHostEventRecorder() { FLAGS_enable_host_event_recorder_hook = true; }
L
liutiexing 已提交
808

C
chenjian 已提交
809 810 811 812
void DisableHostEventRecorder() {
  FLAGS_enable_host_event_recorder_hook = false;
}

L
liutiexing 已提交
813 814
std::string PrintHostEvents() {
  std::ostringstream oss;
L
liutiexing 已提交
815 816
  auto host_evt_sec =
      HostEventRecorder<CommonEvent>::GetInstance().GatherEvents();
L
liutiexing 已提交
817 818 819
  for (const auto &thr_evt_sec : host_evt_sec.thr_sections) {
    oss << thr_evt_sec.thread_id << std::endl;
    for (const auto &evt : thr_evt_sec.events) {
L
liutiexing 已提交
820 821 822
      oss << "{ " << evt.name << " | " << evt.start_ns << "ns | " << evt.end_ns
          << "ns | " << (evt.end_ns - evt.start_ns) / 1000.000 << "us }"
          << std::endl;
L
liutiexing 已提交
823 824 825 826 827
    }
  }
  return oss.str();
}

L
liutiexing 已提交
828 829 830
static void EmulateEventPushAndPop(
    const HostEventSection<CommonEvent> &host_sec,
    std::map<uint64_t, ThreadEvents> *out) {
831 832 833 834 835 836 837 838 839 840 841 842 843 844 845 846 847 848 849 850 851 852 853 854 855 856 857 858 859 860 861 862 863 864 865 866 867 868
  for (const auto &thr_sec : host_sec.thr_sections) {
    uint64_t tid = thr_sec.thread_id;
    auto cur_thr_list = std::make_shared<EventList<Event>>();
    g_all_event_lists.emplace_front(cur_thr_list);
    // for nesting events
    std::stack<size_t> evt_stk;
    std::stack<std::string> prefix_stk;
    std::map<uint64_t, size_t> start2evt;
    for (size_t i = 0; i < thr_sec.events.size(); ++i) {
      const auto &evt = thr_sec.events[i];
      start2evt[evt.start_ns] = i;
    }
    auto iter = start2evt.begin();
    // loop events
    for (size_t i = 0; i < thr_sec.events.size(); ++i) {
      const auto &thr_evts = thr_sec.events;
      const auto &evt = thr_evts[i];
      // For nesting events
      while (!evt_stk.empty() && thr_evts[evt_stk.top()].end_ns <= evt.end_ns) {
        evt_stk.pop();
        prefix_stk.pop();
      }
      while (iter != start2evt.end() &&
             thr_evts[iter->second].start_ns < evt.start_ns) {
        if (thr_evts[iter->second].end_ns > evt.start_ns) {
          evt_stk.push(iter->second);
          std::string prefix = thr_evts[iter->second].name;
          if (!prefix_stk.empty()) {
            prefix = prefix_stk.top() + "/" + prefix;
          }
          prefix_stk.push(prefix);
        }
        ++iter;
      }
      // Record orig event pair
      std::string name =
          prefix_stk.empty() ? evt.name : prefix_stk.top() + "/" + evt.name;
      const char *attr = (evt.attr == nullptr ? "none" : evt.attr);
869 870
      Event *orig_evt = cur_thr_list->Record(
          EventType::kPushRange, name, tid, evt.role, attr);
871 872 873 874 875 876
      (*out)[tid][evt.end_ns] = std::make_pair(orig_evt, evt.start_ns);
      cur_thr_list->Record(EventType::kPopRange, name, tid, evt.role, attr);
    }
  }
}

L
liutiexing 已提交
877 878
static void EmulateCPURecordsAdd(
    const HostEventSection<CommonEvent> &host_sec) {
879 880 881 882 883 884 885
  DeviceTracer *tracer = GetDeviceTracer();
  if (tracer == nullptr) {
    return;
  }
  for (const auto &thr_sec : host_sec.thr_sections) {
    uint64_t tid = thr_sec.thread_id;
    for (const auto &evt : thr_sec.events) {
886 887
      tracer->AddCPURecords(
          evt.name, evt.start_ns, evt.end_ns, BlockDepth(), tid);
888 889 890 891 892 893 894 895 896 897 898 899 900 901 902 903 904 905
    }
  }
}

static void EmulateCorrelation(
    const std::map<uint64_t, ThreadEvents> &thr_events) {
  DeviceTracer *tracer = GetDeviceTracer();
  if (tracer == nullptr) {
    return;
  }
  tracer->AddAnnotations(thr_events);
}

static std::map<uint64_t, ThreadEvents> DockHostEventRecorderHostPart() {
  std::map<uint64_t, ThreadEvents> thr_events;
  if (FLAGS_enable_host_event_recorder_hook == false) {
    return thr_events;
  }
L
liutiexing 已提交
906 907
  auto host_evt_sec =
      HostEventRecorder<CommonEvent>::GetInstance().GatherEvents();
908 909
  EmulateEventPushAndPop(host_evt_sec, &thr_events);
  EmulateCPURecordsAdd(host_evt_sec);
910
  return thr_events;
911 912 913 914 915 916 917 918 919 920
}

static void DockHostEventRecorderDevicePart(
    const std::map<uint64_t, ThreadEvents> &thr_events) {
  if (FLAGS_enable_host_event_recorder_hook == false) {
    return;
  }
  EmulateCorrelation(thr_events);
}

D
dangqingqing 已提交
921 922
}  // namespace platform
}  // namespace paddle