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 "src/debug/debug.h"
      8 #include "src/deoptimizer.h"
      9 #include "src/frames-inl.h"
     10 #include "src/locked-queue-inl.h"
     11 #include "src/log-inl.h"
     12 #include "src/profiler/cpu-profiler-inl.h"
     13 #include "src/vm-state-inl.h"
     14 
     15 #include "include/v8-profiler.h"
     16 
     17 namespace v8 {
     18 namespace internal {
     19 
     20 static const int kProfilerStackSize = 64 * KB;
     21 
     22 
     23 ProfilerEventsProcessor::ProfilerEventsProcessor(ProfileGenerator* generator,
     24                                                  Sampler* sampler,
     25                                                  base::TimeDelta period)
     26     : Thread(Thread::Options("v8:ProfEvntProc", kProfilerStackSize)),
     27       generator_(generator),
     28       sampler_(sampler),
     29       running_(1),
     30       period_(period),
     31       last_code_event_id_(0),
     32       last_processed_code_event_id_(0) {}
     33 
     34 
     35 ProfilerEventsProcessor::~ProfilerEventsProcessor() {}
     36 
     37 
     38 void ProfilerEventsProcessor::Enqueue(const CodeEventsContainer& event) {
     39   event.generic.order = last_code_event_id_.Increment(1);
     40   events_buffer_.Enqueue(event);
     41 }
     42 
     43 
     44 void ProfilerEventsProcessor::AddDeoptStack(Isolate* isolate, Address from,
     45                                             int fp_to_sp_delta) {
     46   TickSampleEventRecord record(last_code_event_id_.Value());
     47   RegisterState regs;
     48   Address fp = isolate->c_entry_fp(isolate->thread_local_top());
     49   regs.sp = fp - fp_to_sp_delta;
     50   regs.fp = fp;
     51   regs.pc = from;
     52   record.sample.Init(isolate, regs, TickSample::kSkipCEntryFrame);
     53   ticks_from_vm_buffer_.Enqueue(record);
     54 }
     55 
     56 
     57 void ProfilerEventsProcessor::AddCurrentStack(Isolate* isolate) {
     58   TickSampleEventRecord record(last_code_event_id_.Value());
     59   RegisterState regs;
     60   StackFrameIterator it(isolate);
     61   if (!it.done()) {
     62     StackFrame* frame = it.frame();
     63     regs.sp = frame->sp();
     64     regs.fp = frame->fp();
     65     regs.pc = frame->pc();
     66   }
     67   record.sample.Init(isolate, regs, TickSample::kSkipCEntryFrame);
     68   ticks_from_vm_buffer_.Enqueue(record);
     69 }
     70 
     71 
     72 void ProfilerEventsProcessor::StopSynchronously() {
     73   if (!base::NoBarrier_AtomicExchange(&running_, 0)) return;
     74   Join();
     75 }
     76 
     77 
     78 bool ProfilerEventsProcessor::ProcessCodeEvent() {
     79   CodeEventsContainer record;
     80   if (events_buffer_.Dequeue(&record)) {
     81     switch (record.generic.type) {
     82 #define PROFILER_TYPE_CASE(type, clss)                          \
     83       case CodeEventRecord::type:                               \
     84         record.clss##_.UpdateCodeMap(generator_->code_map());   \
     85         break;
     86 
     87       CODE_EVENTS_TYPE_LIST(PROFILER_TYPE_CASE)
     88 
     89 #undef PROFILER_TYPE_CASE
     90       default: return true;  // Skip record.
     91     }
     92     last_processed_code_event_id_ = record.generic.order;
     93     return true;
     94   }
     95   return false;
     96 }
     97 
     98 ProfilerEventsProcessor::SampleProcessingResult
     99     ProfilerEventsProcessor::ProcessOneSample() {
    100   TickSampleEventRecord record1;
    101   if (ticks_from_vm_buffer_.Peek(&record1) &&
    102       (record1.order == last_processed_code_event_id_)) {
    103     TickSampleEventRecord record;
    104     ticks_from_vm_buffer_.Dequeue(&record);
    105     generator_->RecordTickSample(record.sample);
    106     return OneSampleProcessed;
    107   }
    108 
    109   const TickSampleEventRecord* record = ticks_buffer_.Peek();
    110   if (record == NULL) {
    111     if (ticks_from_vm_buffer_.IsEmpty()) return NoSamplesInQueue;
    112     return FoundSampleForNextCodeEvent;
    113   }
    114   if (record->order != last_processed_code_event_id_) {
    115     return FoundSampleForNextCodeEvent;
    116   }
    117   generator_->RecordTickSample(record->sample);
    118   ticks_buffer_.Remove();
    119   return OneSampleProcessed;
    120 }
    121 
    122 
    123 void ProfilerEventsProcessor::Run() {
    124   while (!!base::NoBarrier_Load(&running_)) {
    125     base::TimeTicks nextSampleTime =
    126         base::TimeTicks::HighResolutionNow() + period_;
    127     base::TimeTicks now;
    128     SampleProcessingResult result;
    129     // Keep processing existing events until we need to do next sample
    130     // or the ticks buffer is empty.
    131     do {
    132       result = ProcessOneSample();
    133       if (result == FoundSampleForNextCodeEvent) {
    134         // All ticks of the current last_processed_code_event_id_ are
    135         // processed, proceed to the next code event.
    136         ProcessCodeEvent();
    137       }
    138       now = base::TimeTicks::HighResolutionNow();
    139     } while (result != NoSamplesInQueue && now < nextSampleTime);
    140 
    141     if (nextSampleTime > now) {
    142 #if V8_OS_WIN
    143       // Do not use Sleep on Windows as it is very imprecise.
    144       // Could be up to 16ms jitter, which is unacceptable for the purpose.
    145       while (base::TimeTicks::HighResolutionNow() < nextSampleTime) {
    146       }
    147 #else
    148       base::OS::Sleep(nextSampleTime - now);
    149 #endif
    150     }
    151 
    152     // Schedule next sample. sampler_ is NULL in tests.
    153     if (sampler_) sampler_->DoSample();
    154   }
    155 
    156   // Process remaining tick events.
    157   do {
    158     SampleProcessingResult result;
    159     do {
    160       result = ProcessOneSample();
    161     } while (result == OneSampleProcessed);
    162   } while (ProcessCodeEvent());
    163 }
    164 
    165 
    166 void* ProfilerEventsProcessor::operator new(size_t size) {
    167   return AlignedAlloc(size, V8_ALIGNOF(ProfilerEventsProcessor));
    168 }
    169 
    170 
    171 void ProfilerEventsProcessor::operator delete(void* ptr) {
    172   AlignedFree(ptr);
    173 }
    174 
    175 
    176 int CpuProfiler::GetProfilesCount() {
    177   // The count of profiles doesn't depend on a security token.
    178   return profiles_->profiles()->length();
    179 }
    180 
    181 
    182 CpuProfile* CpuProfiler::GetProfile(int index) {
    183   return profiles_->profiles()->at(index);
    184 }
    185 
    186 
    187 void CpuProfiler::DeleteAllProfiles() {
    188   if (is_profiling_) StopProcessor();
    189   ResetProfiles();
    190 }
    191 
    192 
    193 void CpuProfiler::DeleteProfile(CpuProfile* profile) {
    194   profiles_->RemoveProfile(profile);
    195   delete profile;
    196   if (profiles_->profiles()->is_empty() && !is_profiling_) {
    197     // If this was the last profile, clean up all accessory data as well.
    198     ResetProfiles();
    199   }
    200 }
    201 
    202 
    203 void CpuProfiler::CallbackEvent(Name* name, Address entry_point) {
    204   CodeEventsContainer evt_rec(CodeEventRecord::CODE_CREATION);
    205   CodeCreateEventRecord* rec = &evt_rec.CodeCreateEventRecord_;
    206   rec->start = entry_point;
    207   rec->entry = profiles_->NewCodeEntry(
    208       Logger::CALLBACK_TAG,
    209       profiles_->GetName(name));
    210   rec->size = 1;
    211   processor_->Enqueue(evt_rec);
    212 }
    213 
    214 
    215 void CpuProfiler::CodeCreateEvent(Logger::LogEventsAndTags tag,
    216                                   Code* code,
    217                                   const char* name) {
    218   CodeEventsContainer evt_rec(CodeEventRecord::CODE_CREATION);
    219   CodeCreateEventRecord* rec = &evt_rec.CodeCreateEventRecord_;
    220   rec->start = code->address();
    221   rec->entry = profiles_->NewCodeEntry(
    222       tag, profiles_->GetFunctionName(name), CodeEntry::kEmptyNamePrefix,
    223       CodeEntry::kEmptyResourceName, CpuProfileNode::kNoLineNumberInfo,
    224       CpuProfileNode::kNoColumnNumberInfo, NULL, code->instruction_start());
    225   rec->size = code->ExecutableSize();
    226   processor_->Enqueue(evt_rec);
    227 }
    228 
    229 
    230 void CpuProfiler::CodeCreateEvent(Logger::LogEventsAndTags tag,
    231                                   Code* code,
    232                                   Name* name) {
    233   CodeEventsContainer evt_rec(CodeEventRecord::CODE_CREATION);
    234   CodeCreateEventRecord* rec = &evt_rec.CodeCreateEventRecord_;
    235   rec->start = code->address();
    236   rec->entry = profiles_->NewCodeEntry(
    237       tag, profiles_->GetFunctionName(name), CodeEntry::kEmptyNamePrefix,
    238       CodeEntry::kEmptyResourceName, CpuProfileNode::kNoLineNumberInfo,
    239       CpuProfileNode::kNoColumnNumberInfo, NULL, code->instruction_start());
    240   rec->size = code->ExecutableSize();
    241   processor_->Enqueue(evt_rec);
    242 }
    243 
    244 
    245 void CpuProfiler::CodeCreateEvent(Logger::LogEventsAndTags tag, Code* code,
    246                                   SharedFunctionInfo* shared,
    247                                   CompilationInfo* info, Name* script_name) {
    248   CodeEventsContainer evt_rec(CodeEventRecord::CODE_CREATION);
    249   CodeCreateEventRecord* rec = &evt_rec.CodeCreateEventRecord_;
    250   rec->start = code->address();
    251   rec->entry = profiles_->NewCodeEntry(
    252       tag, profiles_->GetFunctionName(shared->DebugName()),
    253       CodeEntry::kEmptyNamePrefix, profiles_->GetName(script_name),
    254       CpuProfileNode::kNoLineNumberInfo, CpuProfileNode::kNoColumnNumberInfo,
    255       NULL, code->instruction_start());
    256   if (info) {
    257     rec->entry->set_inlined_function_infos(info->inlined_function_infos());
    258   }
    259   rec->entry->FillFunctionInfo(shared);
    260   rec->size = code->ExecutableSize();
    261   processor_->Enqueue(evt_rec);
    262 }
    263 
    264 
    265 void CpuProfiler::CodeCreateEvent(Logger::LogEventsAndTags tag, Code* code,
    266                                   SharedFunctionInfo* shared,
    267                                   CompilationInfo* info, Name* script_name,
    268                                   int line, int column) {
    269   CodeEventsContainer evt_rec(CodeEventRecord::CODE_CREATION);
    270   CodeCreateEventRecord* rec = &evt_rec.CodeCreateEventRecord_;
    271   rec->start = code->address();
    272   Script* script = Script::cast(shared->script());
    273   JITLineInfoTable* line_table = NULL;
    274   if (script) {
    275     line_table = new JITLineInfoTable();
    276     for (RelocIterator it(code); !it.done(); it.next()) {
    277       RelocInfo::Mode mode = it.rinfo()->rmode();
    278       if (RelocInfo::IsPosition(mode)) {
    279         int position = static_cast<int>(it.rinfo()->data());
    280         if (position >= 0) {
    281           int pc_offset = static_cast<int>(it.rinfo()->pc() - code->address());
    282           int line_number = script->GetLineNumber(position) + 1;
    283           line_table->SetPosition(pc_offset, line_number);
    284         }
    285       }
    286     }
    287   }
    288   rec->entry = profiles_->NewCodeEntry(
    289       tag, profiles_->GetFunctionName(shared->DebugName()),
    290       CodeEntry::kEmptyNamePrefix, profiles_->GetName(script_name), line,
    291       column, line_table, code->instruction_start());
    292   if (info) {
    293     rec->entry->set_inlined_function_infos(info->inlined_function_infos());
    294   }
    295   rec->entry->FillFunctionInfo(shared);
    296   rec->size = code->ExecutableSize();
    297   processor_->Enqueue(evt_rec);
    298 }
    299 
    300 
    301 void CpuProfiler::CodeCreateEvent(Logger::LogEventsAndTags tag,
    302                                   Code* code,
    303                                   int args_count) {
    304   CodeEventsContainer evt_rec(CodeEventRecord::CODE_CREATION);
    305   CodeCreateEventRecord* rec = &evt_rec.CodeCreateEventRecord_;
    306   rec->start = code->address();
    307   rec->entry = profiles_->NewCodeEntry(
    308       tag, profiles_->GetName(args_count), "args_count: ",
    309       CodeEntry::kEmptyResourceName, CpuProfileNode::kNoLineNumberInfo,
    310       CpuProfileNode::kNoColumnNumberInfo, NULL, code->instruction_start());
    311   rec->size = code->ExecutableSize();
    312   processor_->Enqueue(evt_rec);
    313 }
    314 
    315 
    316 void CpuProfiler::CodeMoveEvent(Address from, Address to) {
    317   CodeEventsContainer evt_rec(CodeEventRecord::CODE_MOVE);
    318   CodeMoveEventRecord* rec = &evt_rec.CodeMoveEventRecord_;
    319   rec->from = from;
    320   rec->to = to;
    321   processor_->Enqueue(evt_rec);
    322 }
    323 
    324 
    325 void CpuProfiler::CodeDisableOptEvent(Code* code, SharedFunctionInfo* shared) {
    326   CodeEventsContainer evt_rec(CodeEventRecord::CODE_DISABLE_OPT);
    327   CodeDisableOptEventRecord* rec = &evt_rec.CodeDisableOptEventRecord_;
    328   rec->start = code->address();
    329   rec->bailout_reason = GetBailoutReason(shared->disable_optimization_reason());
    330   processor_->Enqueue(evt_rec);
    331 }
    332 
    333 
    334 void CpuProfiler::CodeDeoptEvent(Code* code, Address pc, int fp_to_sp_delta) {
    335   CodeEventsContainer evt_rec(CodeEventRecord::CODE_DEOPT);
    336   CodeDeoptEventRecord* rec = &evt_rec.CodeDeoptEventRecord_;
    337   Deoptimizer::DeoptInfo info = Deoptimizer::GetDeoptInfo(code, pc);
    338   rec->start = code->address();
    339   rec->deopt_reason = Deoptimizer::GetDeoptReason(info.deopt_reason);
    340   rec->position = info.position;
    341   rec->pc_offset = pc - code->instruction_start();
    342   processor_->Enqueue(evt_rec);
    343   processor_->AddDeoptStack(isolate_, pc, fp_to_sp_delta);
    344 }
    345 
    346 
    347 void CpuProfiler::CodeDeleteEvent(Address from) {
    348 }
    349 
    350 
    351 void CpuProfiler::GetterCallbackEvent(Name* name, Address entry_point) {
    352   CodeEventsContainer evt_rec(CodeEventRecord::CODE_CREATION);
    353   CodeCreateEventRecord* rec = &evt_rec.CodeCreateEventRecord_;
    354   rec->start = entry_point;
    355   rec->entry = profiles_->NewCodeEntry(
    356       Logger::CALLBACK_TAG,
    357       profiles_->GetName(name),
    358       "get ");
    359   rec->size = 1;
    360   processor_->Enqueue(evt_rec);
    361 }
    362 
    363 
    364 void CpuProfiler::RegExpCodeCreateEvent(Code* code, String* source) {
    365   CodeEventsContainer evt_rec(CodeEventRecord::CODE_CREATION);
    366   CodeCreateEventRecord* rec = &evt_rec.CodeCreateEventRecord_;
    367   rec->start = code->address();
    368   rec->entry = profiles_->NewCodeEntry(
    369       Logger::REG_EXP_TAG, profiles_->GetName(source), "RegExp: ",
    370       CodeEntry::kEmptyResourceName, CpuProfileNode::kNoLineNumberInfo,
    371       CpuProfileNode::kNoColumnNumberInfo, NULL, code->instruction_start());
    372   rec->size = code->ExecutableSize();
    373   processor_->Enqueue(evt_rec);
    374 }
    375 
    376 
    377 void CpuProfiler::SetterCallbackEvent(Name* name, Address entry_point) {
    378   CodeEventsContainer evt_rec(CodeEventRecord::CODE_CREATION);
    379   CodeCreateEventRecord* rec = &evt_rec.CodeCreateEventRecord_;
    380   rec->start = entry_point;
    381   rec->entry = profiles_->NewCodeEntry(
    382       Logger::CALLBACK_TAG,
    383       profiles_->GetName(name),
    384       "set ");
    385   rec->size = 1;
    386   processor_->Enqueue(evt_rec);
    387 }
    388 
    389 
    390 CpuProfiler::CpuProfiler(Isolate* isolate)
    391     : isolate_(isolate),
    392       sampling_interval_(base::TimeDelta::FromMicroseconds(
    393           FLAG_cpu_profiler_sampling_interval)),
    394       profiles_(new CpuProfilesCollection(isolate->heap())),
    395       generator_(NULL),
    396       processor_(NULL),
    397       is_profiling_(false) {
    398 }
    399 
    400 
    401 CpuProfiler::CpuProfiler(Isolate* isolate,
    402                          CpuProfilesCollection* test_profiles,
    403                          ProfileGenerator* test_generator,
    404                          ProfilerEventsProcessor* test_processor)
    405     : isolate_(isolate),
    406       sampling_interval_(base::TimeDelta::FromMicroseconds(
    407           FLAG_cpu_profiler_sampling_interval)),
    408       profiles_(test_profiles),
    409       generator_(test_generator),
    410       processor_(test_processor),
    411       is_profiling_(false) {
    412 }
    413 
    414 
    415 CpuProfiler::~CpuProfiler() {
    416   DCHECK(!is_profiling_);
    417   delete profiles_;
    418 }
    419 
    420 
    421 void CpuProfiler::set_sampling_interval(base::TimeDelta value) {
    422   DCHECK(!is_profiling_);
    423   sampling_interval_ = value;
    424 }
    425 
    426 
    427 void CpuProfiler::ResetProfiles() {
    428   delete profiles_;
    429   profiles_ = new CpuProfilesCollection(isolate()->heap());
    430 }
    431 
    432 
    433 void CpuProfiler::StartProfiling(const char* title, bool record_samples) {
    434   if (profiles_->StartProfiling(title, record_samples)) {
    435     StartProcessorIfNotStarted();
    436   }
    437 }
    438 
    439 
    440 void CpuProfiler::StartProfiling(String* title, bool record_samples) {
    441   StartProfiling(profiles_->GetName(title), record_samples);
    442   isolate_->debug()->feature_tracker()->Track(DebugFeatureTracker::kProfiler);
    443 }
    444 
    445 
    446 void CpuProfiler::StartProcessorIfNotStarted() {
    447   if (processor_ != NULL) {
    448     processor_->AddCurrentStack(isolate_);
    449     return;
    450   }
    451   Logger* logger = isolate_->logger();
    452   // Disable logging when using the new implementation.
    453   saved_is_logging_ = logger->is_logging_;
    454   logger->is_logging_ = false;
    455   generator_ = new ProfileGenerator(profiles_);
    456   Sampler* sampler = logger->sampler();
    457   processor_ = new ProfilerEventsProcessor(
    458       generator_, sampler, sampling_interval_);
    459   is_profiling_ = true;
    460   // Enumerate stuff we already have in the heap.
    461   DCHECK(isolate_->heap()->HasBeenSetUp());
    462   if (!FLAG_prof_browser_mode) {
    463     logger->LogCodeObjects();
    464   }
    465   logger->LogCompiledFunctions();
    466   logger->LogAccessorCallbacks();
    467   LogBuiltins();
    468   // Enable stack sampling.
    469   sampler->SetHasProcessingThread(true);
    470   sampler->IncreaseProfilingDepth();
    471   processor_->AddCurrentStack(isolate_);
    472   processor_->StartSynchronously();
    473 }
    474 
    475 
    476 CpuProfile* CpuProfiler::StopProfiling(const char* title) {
    477   if (!is_profiling_) return NULL;
    478   StopProcessorIfLastProfile(title);
    479   CpuProfile* result = profiles_->StopProfiling(title);
    480   if (result != NULL) {
    481     result->Print();
    482   }
    483   return result;
    484 }
    485 
    486 
    487 CpuProfile* CpuProfiler::StopProfiling(String* title) {
    488   if (!is_profiling_) return NULL;
    489   const char* profile_title = profiles_->GetName(title);
    490   StopProcessorIfLastProfile(profile_title);
    491   return profiles_->StopProfiling(profile_title);
    492 }
    493 
    494 
    495 void CpuProfiler::StopProcessorIfLastProfile(const char* title) {
    496   if (profiles_->IsLastProfile(title)) StopProcessor();
    497 }
    498 
    499 
    500 void CpuProfiler::StopProcessor() {
    501   Logger* logger = isolate_->logger();
    502   Sampler* sampler = reinterpret_cast<Sampler*>(logger->ticker_);
    503   is_profiling_ = false;
    504   processor_->StopSynchronously();
    505   delete processor_;
    506   delete generator_;
    507   processor_ = NULL;
    508   generator_ = NULL;
    509   sampler->SetHasProcessingThread(false);
    510   sampler->DecreaseProfilingDepth();
    511   logger->is_logging_ = saved_is_logging_;
    512 }
    513 
    514 
    515 void CpuProfiler::LogBuiltins() {
    516   Builtins* builtins = isolate_->builtins();
    517   DCHECK(builtins->is_initialized());
    518   for (int i = 0; i < Builtins::builtin_count; i++) {
    519     CodeEventsContainer evt_rec(CodeEventRecord::REPORT_BUILTIN);
    520     ReportBuiltinEventRecord* rec = &evt_rec.ReportBuiltinEventRecord_;
    521     Builtins::Name id = static_cast<Builtins::Name>(i);
    522     rec->start = builtins->builtin(id)->address();
    523     rec->builtin_id = id;
    524     processor_->Enqueue(evt_rec);
    525   }
    526 }
    527 
    528 
    529 }  // namespace internal
    530 }  // namespace v8
    531