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