Home | History | Annotate | Download | only in profiler 
      1 // Copyright 2012 the V8 project authors. All rights reserved.
      2 // Use of this source code is governed by a BSD-style license that can be
      3 // found in the LICENSE file.
      4 
      5 #include "src/profiler/cpu-profiler.h"
      6 
      7 #include <unordered_map>
      8 #include <utility>
      9 
     10 #include "src/base/lazy-instance.h"
     11 #include "src/base/platform/mutex.h"
     12 #include "src/base/template-utils.h"
     13 #include "src/debug/debug.h"
     14 #include "src/deoptimizer.h"
     15 #include "src/frames-inl.h"
     16 #include "src/locked-queue-inl.h"
     17 #include "src/log-inl.h"
     18 #include "src/profiler/cpu-profiler-inl.h"
     19 #include "src/vm-state-inl.h"
     20 
     21 namespace v8 {
     22 namespace internal {
     23 
     24 static const int kProfilerStackSize = 64 * KB;
     25 
     26 class CpuSampler : public sampler::Sampler {
     27  public:
     28   CpuSampler(Isolate* isolate, ProfilerEventsProcessor* processor)
     29       : sampler::Sampler(reinterpret_cast<v8::Isolate*>(isolate)),
     30         processor_(processor) {}
     31 
     32   void SampleStack(const v8::RegisterState& regs) override {
     33     TickSample* sample = processor_->StartTickSample();
     34     if (sample == nullptr) return;
     35     Isolate* isolate = reinterpret_cast<Isolate*>(this->isolate());
     36     sample->Init(isolate, regs, TickSample::kIncludeCEntryFrame, true);
     37     if (is_counting_samples_ && !sample->timestamp.IsNull()) {
     38       if (sample->state == JS) ++js_sample_count_;
     39       if (sample->state == EXTERNAL) ++external_sample_count_;
     40     }
     41     processor_->FinishTickSample();
     42   }
     43 
     44  private:
     45   ProfilerEventsProcessor* processor_;
     46 };
     47 
     48 ProfilerEventsProcessor::ProfilerEventsProcessor(Isolate* isolate,
     49                                                  ProfileGenerator* generator,
     50                                                  base::TimeDelta period)
     51     : Thread(Thread::Options("v8:ProfEvntProc", kProfilerStackSize)),
     52       generator_(generator),
     53       sampler_(new CpuSampler(isolate, this)),
     54       running_(1),
     55       period_(period),
     56       last_code_event_id_(0),
     57       last_processed_code_event_id_(0) {
     58   sampler_->IncreaseProfilingDepth();
     59 }
     60 
     61 ProfilerEventsProcessor::~ProfilerEventsProcessor() {
     62   sampler_->DecreaseProfilingDepth();
     63 }
     64 
     65 void ProfilerEventsProcessor::Enqueue(const CodeEventsContainer& event) {
     66   event.generic.order = ++last_code_event_id_;
     67   events_buffer_.Enqueue(event);
     68 }
     69 
     70 
     71 void ProfilerEventsProcessor::AddDeoptStack(Isolate* isolate, Address from,
     72                                             int fp_to_sp_delta) {
     73   TickSampleEventRecord record(last_code_event_id_);
     74   RegisterState regs;
     75   Address fp = isolate->c_entry_fp(isolate->thread_local_top());
     76   regs.sp = reinterpret_cast<void*>(fp - fp_to_sp_delta);
     77   regs.fp = reinterpret_cast<void*>(fp);
     78   regs.pc = reinterpret_cast<void*>(from);
     79   record.sample.Init(isolate, regs, TickSample::kSkipCEntryFrame, false, false);
     80   ticks_from_vm_buffer_.Enqueue(record);
     81 }
     82 
     83 void ProfilerEventsProcessor::AddCurrentStack(Isolate* isolate,
     84                                               bool update_stats) {
     85   TickSampleEventRecord record(last_code_event_id_);
     86   RegisterState regs;
     87   StackFrameIterator it(isolate);
     88   if (!it.done()) {
     89     StackFrame* frame = it.frame();
     90     regs.sp = reinterpret_cast<void*>(frame->sp());
     91     regs.fp = reinterpret_cast<void*>(frame->fp());
     92     regs.pc = reinterpret_cast<void*>(frame->pc());
     93   }
     94   record.sample.Init(isolate, regs, TickSample::kSkipCEntryFrame, update_stats,
     95                      false);
     96   ticks_from_vm_buffer_.Enqueue(record);
     97 }
     98 
     99 
    100 void ProfilerEventsProcessor::StopSynchronously() {
    101   if (!base::Relaxed_AtomicExchange(&running_, 0)) return;
    102   Join();
    103 }
    104 
    105 
    106 bool ProfilerEventsProcessor::ProcessCodeEvent() {
    107   CodeEventsContainer record;
    108   if (events_buffer_.Dequeue(&record)) {
    109     switch (record.generic.type) {
    110 #define PROFILER_TYPE_CASE(type, clss)                          \
    111       case CodeEventRecord::type:                               \
    112         record.clss##_.UpdateCodeMap(generator_->code_map());   \
    113         break;
    114 
    115       CODE_EVENTS_TYPE_LIST(PROFILER_TYPE_CASE)
    116 
    117 #undef PROFILER_TYPE_CASE
    118       default: return true;  // Skip record.
    119     }
    120     last_processed_code_event_id_ = record.generic.order;
    121     return true;
    122   }
    123   return false;
    124 }
    125 
    126 ProfilerEventsProcessor::SampleProcessingResult
    127     ProfilerEventsProcessor::ProcessOneSample() {
    128   TickSampleEventRecord record1;
    129   if (ticks_from_vm_buffer_.Peek(&record1) &&
    130       (record1.order == last_processed_code_event_id_)) {
    131     TickSampleEventRecord record;
    132     ticks_from_vm_buffer_.Dequeue(&record);
    133     generator_->RecordTickSample(record.sample);
    134     return OneSampleProcessed;
    135   }
    136 
    137   const TickSampleEventRecord* record = ticks_buffer_.Peek();
    138   if (record == nullptr) {
    139     if (ticks_from_vm_buffer_.IsEmpty()) return NoSamplesInQueue;
    140     return FoundSampleForNextCodeEvent;
    141   }
    142   if (record->order != last_processed_code_event_id_) {
    143     return FoundSampleForNextCodeEvent;
    144   }
    145   generator_->RecordTickSample(record->sample);
    146   ticks_buffer_.Remove();
    147   return OneSampleProcessed;
    148 }
    149 
    150 
    151 void ProfilerEventsProcessor::Run() {
    152   while (!!base::Relaxed_Load(&running_)) {
    153     base::TimeTicks nextSampleTime =
    154         base::TimeTicks::HighResolutionNow() + period_;
    155     base::TimeTicks now;
    156     SampleProcessingResult result;
    157     // Keep processing existing events until we need to do next sample
    158     // or the ticks buffer is empty.
    159     do {
    160       result = ProcessOneSample();
    161       if (result == FoundSampleForNextCodeEvent) {
    162         // All ticks of the current last_processed_code_event_id_ are
    163         // processed, proceed to the next code event.
    164         ProcessCodeEvent();
    165       }
    166       now = base::TimeTicks::HighResolutionNow();
    167     } while (result != NoSamplesInQueue && now < nextSampleTime);
    168 
    169     if (nextSampleTime > now) {
    170 #if V8_OS_WIN
    171       if (nextSampleTime - now < base::TimeDelta::FromMilliseconds(100)) {
    172         // Do not use Sleep on Windows as it is very imprecise, with up to 16ms
    173         // jitter, which is unacceptable for short profile intervals.
    174         while (base::TimeTicks::HighResolutionNow() < nextSampleTime) {
    175         }
    176       } else  // NOLINT
    177 #endif
    178       {
    179         base::OS::Sleep(nextSampleTime - now);
    180       }
    181     }
    182 
    183     // Schedule next sample. sampler_ is nullptr in tests.
    184     if (sampler_) sampler_->DoSample();
    185   }
    186 
    187   // Process remaining tick events.
    188   do {
    189     SampleProcessingResult result;
    190     do {
    191       result = ProcessOneSample();
    192     } while (result == OneSampleProcessed);
    193   } while (ProcessCodeEvent());
    194 }
    195 
    196 
    197 void* ProfilerEventsProcessor::operator new(size_t size) {
    198   return AlignedAlloc(size, V8_ALIGNOF(ProfilerEventsProcessor));
    199 }
    200 
    201 
    202 void ProfilerEventsProcessor::operator delete(void* ptr) {
    203   AlignedFree(ptr);
    204 }
    205 
    206 
    207 int CpuProfiler::GetProfilesCount() {
    208   // The count of profiles doesn't depend on a security token.
    209   return static_cast<int>(profiles_->profiles()->size());
    210 }
    211 
    212 
    213 CpuProfile* CpuProfiler::GetProfile(int index) {
    214   return profiles_->profiles()->at(index).get();
    215 }
    216 
    217 
    218 void CpuProfiler::DeleteAllProfiles() {
    219   if (is_profiling_) StopProcessor();
    220   ResetProfiles();
    221 }
    222 
    223 
    224 void CpuProfiler::DeleteProfile(CpuProfile* profile) {
    225   profiles_->RemoveProfile(profile);
    226   if (profiles_->profiles()->empty() && !is_profiling_) {
    227     // If this was the last profile, clean up all accessory data as well.
    228     ResetProfiles();
    229   }
    230 }
    231 
    232 void CpuProfiler::CodeEventHandler(const CodeEventsContainer& evt_rec) {
    233   switch (evt_rec.generic.type) {
    234     case CodeEventRecord::CODE_CREATION:
    235     case CodeEventRecord::CODE_MOVE:
    236     case CodeEventRecord::CODE_DISABLE_OPT:
    237       processor_->Enqueue(evt_rec);
    238       break;
    239     case CodeEventRecord::CODE_DEOPT: {
    240       const CodeDeoptEventRecord* rec = &evt_rec.CodeDeoptEventRecord_;
    241       Address pc = rec->pc;
    242       int fp_to_sp_delta = rec->fp_to_sp_delta;
    243       processor_->Enqueue(evt_rec);
    244       processor_->AddDeoptStack(isolate_, pc, fp_to_sp_delta);
    245       break;
    246     }
    247     default:
    248       UNREACHABLE();
    249   }
    250 }
    251 
    252 namespace {
    253 
    254 class CpuProfilersManager {
    255  public:
    256   void AddProfiler(Isolate* isolate, CpuProfiler* profiler) {
    257     base::LockGuard<base::Mutex> lock(&mutex_);
    258     profilers_.emplace(isolate, profiler);
    259   }
    260 
    261   void RemoveProfiler(Isolate* isolate, CpuProfiler* profiler) {
    262     base::LockGuard<base::Mutex> lock(&mutex_);
    263     auto range = profilers_.equal_range(isolate);
    264     for (auto it = range.first; it != range.second; ++it) {
    265       if (it->second != profiler) continue;
    266       profilers_.erase(it);
    267       return;
    268     }
    269     UNREACHABLE();
    270   }
    271 
    272   void CallCollectSample(Isolate* isolate) {
    273     base::LockGuard<base::Mutex> lock(&mutex_);
    274     auto range = profilers_.equal_range(isolate);
    275     for (auto it = range.first; it != range.second; ++it) {
    276       it->second->CollectSample();
    277     }
    278   }
    279 
    280  private:
    281   std::unordered_multimap<Isolate*, CpuProfiler*> profilers_;
    282   base::Mutex mutex_;
    283 };
    284 
    285 base::LazyInstance<CpuProfilersManager>::type g_profilers_manager =
    286     LAZY_INSTANCE_INITIALIZER;
    287 
    288 }  // namespace
    289 
    290 CpuProfiler::CpuProfiler(Isolate* isolate)
    291     : CpuProfiler(isolate, new CpuProfilesCollection(isolate), nullptr,
    292                   nullptr) {}
    293 
    294 CpuProfiler::CpuProfiler(Isolate* isolate, CpuProfilesCollection* test_profiles,
    295                          ProfileGenerator* test_generator,
    296                          ProfilerEventsProcessor* test_processor)
    297     : isolate_(isolate),
    298       sampling_interval_(base::TimeDelta::FromMicroseconds(
    299           FLAG_cpu_profiler_sampling_interval)),
    300       profiles_(test_profiles),
    301       generator_(test_generator),
    302       processor_(test_processor),
    303       is_profiling_(false) {
    304   profiles_->set_cpu_profiler(this);
    305   g_profilers_manager.Pointer()->AddProfiler(isolate, this);
    306 }
    307 
    308 CpuProfiler::~CpuProfiler() {
    309   DCHECK(!is_profiling_);
    310   g_profilers_manager.Pointer()->RemoveProfiler(isolate_, this);
    311 }
    312 
    313 void CpuProfiler::set_sampling_interval(base::TimeDelta value) {
    314   DCHECK(!is_profiling_);
    315   sampling_interval_ = value;
    316 }
    317 
    318 void CpuProfiler::ResetProfiles() {
    319   profiles_.reset(new CpuProfilesCollection(isolate_));
    320   profiles_->set_cpu_profiler(this);
    321   profiler_listener_.reset();
    322   generator_.reset();
    323 }
    324 
    325 void CpuProfiler::CreateEntriesForRuntimeCallStats() {
    326   RuntimeCallStats* rcs = isolate_->counters()->runtime_call_stats();
    327   CodeMap* code_map = generator_->code_map();
    328   for (int i = 0; i < RuntimeCallStats::kNumberOfCounters; ++i) {
    329     RuntimeCallCounter* counter = rcs->GetCounter(i);
    330     DCHECK(counter->name());
    331     auto entry = new CodeEntry(CodeEventListener::FUNCTION_TAG, counter->name(),
    332                                "native V8Runtime");
    333     code_map->AddCode(reinterpret_cast<Address>(counter), entry, 1);
    334   }
    335 }
    336 
    337 // static
    338 void CpuProfiler::CollectSample(Isolate* isolate) {
    339   g_profilers_manager.Pointer()->CallCollectSample(isolate);
    340 }
    341 
    342 void CpuProfiler::CollectSample() {
    343   if (processor_) {
    344     processor_->AddCurrentStack(isolate_);
    345   }
    346 }
    347 
    348 void CpuProfiler::StartProfiling(const char* title, bool record_samples,
    349                                  ProfilingMode mode) {
    350   if (profiles_->StartProfiling(title, record_samples, mode)) {
    351     TRACE_EVENT0("v8", "CpuProfiler::StartProfiling");
    352     StartProcessorIfNotStarted();
    353   }
    354 }
    355 
    356 void CpuProfiler::StartProfiling(String* title, bool record_samples,
    357                                  ProfilingMode mode) {
    358   StartProfiling(profiles_->GetName(title), record_samples, mode);
    359   isolate_->debug()->feature_tracker()->Track(DebugFeatureTracker::kProfiler);
    360 }
    361 
    362 void CpuProfiler::StartProcessorIfNotStarted() {
    363   if (processor_) {
    364     processor_->AddCurrentStack(isolate_);
    365     return;
    366   }
    367   Logger* logger = isolate_->logger();
    368   // Disable logging when using the new implementation.
    369   saved_is_logging_ = logger->is_logging_;
    370   logger->is_logging_ = false;
    371 
    372   bool codemap_needs_initialization = false;
    373   if (!generator_) {
    374     generator_.reset(new ProfileGenerator(profiles_.get()));
    375     codemap_needs_initialization = true;
    376     CreateEntriesForRuntimeCallStats();
    377   }
    378   processor_.reset(new ProfilerEventsProcessor(isolate_, generator_.get(),
    379                                                sampling_interval_));
    380   if (!profiler_listener_) {
    381     profiler_listener_.reset(new ProfilerListener(isolate_, this));
    382   }
    383   logger->AddCodeEventListener(profiler_listener_.get());
    384   is_profiling_ = true;
    385   isolate_->set_is_profiling(true);
    386   // Enumerate stuff we already have in the heap.
    387   DCHECK(isolate_->heap()->HasBeenSetUp());
    388   if (codemap_needs_initialization) {
    389     if (!FLAG_prof_browser_mode) {
    390       logger->LogCodeObjects();
    391     }
    392     logger->LogCompiledFunctions();
    393     logger->LogAccessorCallbacks();
    394     LogBuiltins();
    395   }
    396   // Enable stack sampling.
    397   processor_->AddCurrentStack(isolate_);
    398   processor_->StartSynchronously();
    399 }
    400 
    401 CpuProfile* CpuProfiler::StopProfiling(const char* title) {
    402   if (!is_profiling_) return nullptr;
    403   StopProcessorIfLastProfile(title);
    404   return profiles_->StopProfiling(title);
    405 }
    406 
    407 CpuProfile* CpuProfiler::StopProfiling(String* title) {
    408   return StopProfiling(profiles_->GetName(title));
    409 }
    410 
    411 void CpuProfiler::StopProcessorIfLastProfile(const char* title) {
    412   if (!profiles_->IsLastProfile(title)) return;
    413   StopProcessor();
    414 }
    415 
    416 void CpuProfiler::StopProcessor() {
    417   Logger* logger = isolate_->logger();
    418   is_profiling_ = false;
    419   isolate_->set_is_profiling(false);
    420   logger->RemoveCodeEventListener(profiler_listener_.get());
    421   processor_->StopSynchronously();
    422   processor_.reset();
    423   logger->is_logging_ = saved_is_logging_;
    424 }
    425 
    426 
    427 void CpuProfiler::LogBuiltins() {
    428   Builtins* builtins = isolate_->builtins();
    429   DCHECK(builtins->is_initialized());
    430   for (int i = 0; i < Builtins::builtin_count; i++) {
    431     CodeEventsContainer evt_rec(CodeEventRecord::REPORT_BUILTIN);
    432     ReportBuiltinEventRecord* rec = &evt_rec.ReportBuiltinEventRecord_;
    433     Builtins::Name id = static_cast<Builtins::Name>(i);
    434     rec->instruction_start = builtins->builtin(id)->InstructionStart();
    435     rec->builtin_id = id;
    436     processor_->Enqueue(evt_rec);
    437   }
    438 }
    439 
    440 }  // namespace internal
    441 }  // namespace v8
    442