profiler.cc 29.5 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 280 281 282 283 284 285 286 287 288 289 290 291 292 293 294 295 296 297 298 299 300 301 302 303 304 305 306 307 308 309 310 311 312 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
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);
}

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 已提交
397
                                    size_t size) {
398 399 400
  if (g_state == ProfilerState::kDisabled) {
    return;
  }
C
chengduo 已提交
401 402
  std::lock_guard<std::mutex> guard(mtx_);
  auto &events = address_memevent_[place];
403 404
  PADDLE_ENFORCE_EQ(events.count(ptr),
                    0,
G
GaoWei8 已提交
405 406
                    platform::errors::InvalidArgument(
                        "The Place can't exist in the stage of PushMemRecord"));
407 408 409 410 411 412 413 414 415 416 417 418 419 420 421 422 423 424 425 426 427 428 429 430 431 432 433 434 435 436 437 438 439 440 441 442 443 444 445 446
  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 已提交
447 448 449
}

void MemEvenRecorder::PopMemRecord(const void *ptr, const Place &place) {
450 451 452
  if (g_state == ProfilerState::kDisabled) {
    return;
  }
C
chengduo 已提交
453 454 455 456 457 458 459 460 461
  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);
  }
}

462 463 464 465 466 467 468 469 470 471 472 473 474 475 476 477 478 479 480 481 482 483 484 485 486 487 488 489 490 491 492 493 494 495 496
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 已提交
497 498 499 500 501 502 503 504 505 506 507 508 509 510 511 512 513 514 515 516
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) {
517 518 519 520 521 522 523
    tracer->AddMemInfoRecord(start_ns_,
                             end_ns_,
                             bytes_,
                             place_,
                             alloc_in_,
                             annotation_free,
                             g_mem_thread_id);
C
chengduo 已提交
524 525 526 527
  }
  PopMemEvent(start_ns_, end_ns_, bytes_, place_, annotation_free);
}

L
liutiexing 已提交
528
/*RecordRPCEvent::RecordRPCEvent(const std::string &name) {
G
gongweibao 已提交
529
  if (FLAGS_enable_rpc_profiler) {
530
    event_.reset(new platform::RecordEvent(name));
G
gongweibao 已提交
531
  }
L
liutiexing 已提交
532
}*/
G
gongweibao 已提交
533

X
Xin Pan 已提交
534 535
RecordBlock::RecordBlock(int block_id)
    : is_enabled_(false), start_ns_(PosixInNsec()) {
536
  // lock is not needed, the code below is thread-safe
X
Xin Pan 已提交
537
  if (g_state == ProfilerState::kDisabled) return;
X
Xin Pan 已提交
538
  is_enabled_ = true;
X
Xin Pan 已提交
539 540 541 542 543
  SetCurBlock(block_id);
  name_ = string::Sprintf("block_%d", block_id);
}

RecordBlock::~RecordBlock() {
544
  // lock is not needed, the code below is thread-safe
X
Xin Pan 已提交
545
  if (g_state == ProfilerState::kDisabled || !is_enabled_) return;
C
chengduo 已提交
546
  DeviceTracer *tracer = GetDeviceTracer();
X
Xin Pan 已提交
547 548 549
  if (tracer) {
    // We try to put all blocks at the same nested depth in the
    // same timeline lane. and distinguish the using thread_id.
550 551
    tracer->AddCPURecords(
        name_, start_ns_, PosixInNsec(), BlockDepth(), g_thread_id);
X
Xin Pan 已提交
552 553 554 555
  }
  ClearCurBlock();
}

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
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 已提交
582 583 584
}

void Mark(const std::string &name) {
585
  if (FLAGS_enable_host_event_recorder_hook) {
L
liutiexing 已提交
586
    HostEventRecorder<CommonEvent>::GetInstance().RecordEvent(
C
chenjian 已提交
587
        name, 0, 0, EventRole::kOrdinary, TracerEventType::UserDefined);
588 589
    return;
  }
W
wangchaochaohu 已提交
590 591 592
  GetEventList().Record(EventType::kMark, name, g_thread_id);
}

593 594
Event *PushEvent(const std::string &name,
                 const EventRole role,
Y
Yuang Liu 已提交
595
                 std::string attr) {
596 597
  return GetEventList().Record(
      EventType::kPushRange, name, g_thread_id, role, attr);
598 599
}

Y
Yuang Liu 已提交
600 601
void PopEvent(const std::string &name, const EventRole role, std::string attr) {
  GetEventList().Record(EventType::kPopRange, name, g_thread_id, role, attr);
W
wangchaochaohu 已提交
602
}
D
dangqingqing 已提交
603
void EnableProfiler(ProfilerState state) {
604 605
  PADDLE_ENFORCE_NE(state,
                    ProfilerState::kDisabled,
W
wangchaochaohu 已提交
606 607 608
                    platform::errors::InvalidArgument(
                        "Can't enable profiling, since the input state is"
                        "ProfilerState::kDisabled"));
609
  SynchronizeAllDevice();
X
Xin Pan 已提交
610
  std::lock_guard<std::mutex> l(profiler_mu);
611 612
  if (state == g_state) {
    return;
613
  }
614
  g_state = state;
C
chenjian 已提交
615 616
  ProfilerOptions option;
  HostTraceLevel::GetInstance().SetLevel(option.trace_level);
X
Xin Pan 已提交
617
  should_send_profile_state = true;
618
  GetDeviceTracer()->Enable();
619
#if defined(PADDLE_WITH_CUDA) || defined(PADDLE_WITH_HIP)
620 621
  if (g_state == ProfilerState::kCUDA || g_state == ProfilerState::kAll ||
      g_state == ProfilerState::kCPU) {
622
    // Generate some dummy events first to reduce the startup overhead.
623 624
    DummyKernelAndEvent();
    GetDeviceTracer()->Reset();
D
dangqingqing 已提交
625 626 627
  }
#endif
  // Mark the profiling start.
628
  Mark("_start_profiler_");
D
dangqingqing 已提交
629 630
}

631
void ResetProfiler() {
632 633
  SynchronizeAllDevice();
  GetDeviceTracer()->Reset();
C
chengduo 已提交
634
  MemEvenRecorder::Instance().Flush();
D
dangqingqing 已提交
635
  std::lock_guard<std::mutex> guard(g_all_event_lists_mutex);
636 637 638 639
  for (auto it = g_all_event_lists.begin(); it != g_all_event_lists.end();
       ++it) {
    (*it)->Clear();
  }
C
chengduo 已提交
640
  for (auto it = g_all_mem_event_lists.begin();
641 642
       it != g_all_mem_event_lists.end();
       ++it) {
C
chengduo 已提交
643 644
    (*it)->Clear();
  }
645 646
}

647 648 649 650
static std::map<uint64_t, ThreadEvents> DockHostEventRecorderHostPart();
static void DockHostEventRecorderDevicePart(
    const std::map<uint64_t, ThreadEvents> &thr_events);

651
void DisableProfiler(EventSortingKey sorted_key,
C
chengduo 已提交
652
                     const std::string &profile_path) {
653
  SynchronizeAllDevice();
654
  auto thr_events = DockHostEventRecorderHostPart();
C
chengduo 已提交
655 656
  MemEvenRecorder::Instance().Flush();

X
Xin Pan 已提交
657
  std::lock_guard<std::mutex> l(profiler_mu);
658
  if (g_state == ProfilerState::kDisabled) return;
659
  // Mark the profiling stop.
660
  Mark("_stop_profiler_");
661
  DealWithShowName();
662

C
chengduo 已提交
663
  DeviceTracer *tracer = GetDeviceTracer();
664
  if (tracer->IsEnabled()) {
665
    tracer->Disable();
666
    DockHostEventRecorderDevicePart(thr_events);
667
    tracer->GenEventKernelCudaElapsedTime();
668
    tracer->GenProfile(profile_path);
669
  }
670 671

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

673 674
  ParseEvents(all_events, true, sorted_key);
  ParseEvents(all_events, false, sorted_key);
H
Huihuang Zheng 已提交
675 676 677 678 679 680 681 682 683 684 685 686 687 688

  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();
689
  auto thr_events = DockHostEventRecorderHostPart();
H
Huihuang Zheng 已提交
690 691 692 693 694 695 696 697 698 699 700
  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();
701
    DockHostEventRecorderDevicePart(thr_events);
H
Huihuang Zheng 已提交
702 703 704 705 706 707 708 709 710
    tracer->GenEventKernelCudaElapsedTime();
    *tracer_profile = tracer->GetProfile();
  }

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

713
  ResetProfiler();
714
  g_state = ProfilerState::kDisabled;
715
  g_tracer_option = TracerOption::kDefault;
X
Xin Pan 已提交
716
  should_send_profile_state = true;
717 718
}

W
wangchaochaohu 已提交
719 720 721 722 723 724 725 726 727 728
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;
}

729 730
bool IsProfileEnabled() { return g_state != ProfilerState::kDisabled; }

W
wangchaochaohu 已提交
731
bool ShouldSendProfileState() { return should_send_profile_state; }
732

733 734
std::string OpName(const framework::VariableNameMap &name_map,
                   const std::string &type_name) {
735 736
  if (platform::GetTracerOption() != platform::TracerOption::kAllOpDetail ||
      !IsProfileEnabled())
737 738 739 740 741
    return "";

  std::string ret = type_name + "%";
  for (auto it = name_map.begin(); it != name_map.end(); it++) {
    auto name_outputs = it->second;
742
    if (!name_outputs.empty()) {
743 744 745 746 747 748 749 750 751 752 753 754 755 756 757
      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 已提交
758 759 760 761 762 763 764 765 766 767 768

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; }

769 770 771 772 773 774 775
void NvprofEnableRecordEvent() {
  SynchronizeAllDevice();
  g_enable_nvprof_hook = true;
}

void NvprofDisableRecordEvent() { g_enable_nvprof_hook = false; }

776
void EnableHostEventRecorder() { FLAGS_enable_host_event_recorder_hook = true; }
L
liutiexing 已提交
777

C
chenjian 已提交
778 779 780 781
void DisableHostEventRecorder() {
  FLAGS_enable_host_event_recorder_hook = false;
}

L
liutiexing 已提交
782 783
std::string PrintHostEvents() {
  std::ostringstream oss;
L
liutiexing 已提交
784 785
  auto host_evt_sec =
      HostEventRecorder<CommonEvent>::GetInstance().GatherEvents();
L
liutiexing 已提交
786 787 788
  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 已提交
789 790 791
      oss << "{ " << evt.name << " | " << evt.start_ns << "ns | " << evt.end_ns
          << "ns | " << (evt.end_ns - evt.start_ns) / 1000.000 << "us }"
          << std::endl;
L
liutiexing 已提交
792 793 794 795 796
    }
  }
  return oss.str();
}

L
liutiexing 已提交
797 798 799
static void EmulateEventPushAndPop(
    const HostEventSection<CommonEvent> &host_sec,
    std::map<uint64_t, ThreadEvents> *out) {
800 801 802 803 804 805 806 807 808 809 810 811 812 813 814 815 816 817 818 819 820 821 822 823 824 825 826 827 828 829 830 831 832 833 834 835 836 837
  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);
838 839
      Event *orig_evt = cur_thr_list->Record(
          EventType::kPushRange, name, tid, evt.role, attr);
840 841 842 843 844 845
      (*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 已提交
846 847
static void EmulateCPURecordsAdd(
    const HostEventSection<CommonEvent> &host_sec) {
848 849 850 851 852 853 854
  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) {
855 856
      tracer->AddCPURecords(
          evt.name, evt.start_ns, evt.end_ns, BlockDepth(), tid);
857 858 859 860 861 862 863 864 865 866 867 868 869 870 871 872 873 874
    }
  }
}

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 已提交
875 876
  auto host_evt_sec =
      HostEventRecorder<CommonEvent>::GetInstance().GatherEvents();
877 878
  EmulateEventPushAndPop(host_evt_sec, &thr_events);
  EmulateCPURecordsAdd(host_evt_sec);
879
  return thr_events;
880 881 882 883 884 885 886 887 888 889
}

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 已提交
890 891
}  // namespace platform
}  // namespace paddle