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 800 : class CpuSampler : public sampler::Sampler {
27 : public:
28 : CpuSampler(Isolate* isolate, SamplingEventsProcessor* processor)
29 : : sampler::Sampler(reinterpret_cast<v8::Isolate*>(isolate)),
30 805 : processor_(processor) {}
31 :
32 66041 : void SampleStack(const v8::RegisterState& regs) override {
33 66041 : TickSample* sample = processor_->StartTickSample();
34 66041 : if (sample == nullptr) return;
35 : Isolate* isolate = reinterpret_cast<Isolate*>(this->isolate());
36 66041 : sample->Init(isolate, regs, TickSample::kIncludeCEntryFrame, true);
37 120424 : if (is_counting_samples_ && !sample->timestamp.IsNull()) {
38 54383 : if (sample->state == JS) ++js_sample_count_;
39 54383 : if (sample->state == EXTERNAL) ++external_sample_count_;
40 : }
41 66041 : processor_->FinishTickSample();
42 : }
43 :
44 : private:
45 : SamplingEventsProcessor* processor_;
46 : };
47 :
48 805 : 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 2415 : isolate_(isolate) {}
56 :
57 805 : SamplingEventsProcessor::SamplingEventsProcessor(Isolate* isolate,
58 : ProfileGenerator* generator,
59 : base::TimeDelta period)
60 : : ProfilerEventsProcessor(isolate, generator),
61 : sampler_(new CpuSampler(isolate, this)),
62 2415 : period_(period) {
63 805 : sampler_->Start();
64 805 : }
65 :
66 4000 : SamplingEventsProcessor::~SamplingEventsProcessor() { sampler_->Stop(); }
67 :
68 : ProfilerEventsProcessor::~ProfilerEventsProcessor() = default;
69 :
70 1816572 : void ProfilerEventsProcessor::Enqueue(const CodeEventsContainer& event) {
71 1816572 : event.generic.order = ++last_code_event_id_;
72 1816572 : events_buffer_.Enqueue(event);
73 1816572 : }
74 :
75 9 : void ProfilerEventsProcessor::AddDeoptStack(Address from, int fp_to_sp_delta) {
76 : TickSampleEventRecord record(last_code_event_id_);
77 : RegisterState regs;
78 9 : Address fp = isolate_->c_entry_fp(isolate_->thread_local_top());
79 9 : regs.sp = reinterpret_cast<void*>(fp - fp_to_sp_delta);
80 9 : regs.fp = reinterpret_cast<void*>(fp);
81 9 : regs.pc = reinterpret_cast<void*>(from);
82 : record.sample.Init(isolate_, regs, TickSample::kSkipCEntryFrame, false,
83 9 : false);
84 9 : ticks_from_vm_buffer_.Enqueue(record);
85 9 : }
86 :
87 951 : void ProfilerEventsProcessor::AddCurrentStack(bool update_stats) {
88 : TickSampleEventRecord record(last_code_event_id_);
89 : RegisterState regs;
90 951 : StackFrameIterator it(isolate_);
91 951 : if (!it.done()) {
92 : StackFrame* frame = it.frame();
93 192 : regs.sp = reinterpret_cast<void*>(frame->sp());
94 192 : regs.fp = reinterpret_cast<void*>(frame->fp());
95 192 : regs.pc = reinterpret_cast<void*>(frame->pc());
96 : }
97 951 : record.sample.Init(isolate_, regs, TickSample::kSkipCEntryFrame, update_stats,
98 951 : false);
99 951 : ticks_from_vm_buffer_.Enqueue(record);
100 951 : }
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 810 : void ProfilerEventsProcessor::StopSynchronously() {
109 1620 : if (!base::Relaxed_AtomicExchange(&running_, 0)) return;
110 : {
111 805 : base::MutexGuard guard(&running_mutex_);
112 805 : running_cond_.NotifyOne();
113 : }
114 805 : Join();
115 : }
116 :
117 :
118 1817284 : bool ProfilerEventsProcessor::ProcessCodeEvent() {
119 : CodeEventsContainer record;
120 1817284 : if (events_buffer_.Dequeue(&record)) {
121 1816455 : 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 1816457 : CODE_EVENTS_TYPE_LIST(PROFILER_TYPE_CASE)
128 :
129 : #undef PROFILER_TYPE_CASE
130 : default: return true; // Skip record.
131 : }
132 1816455 : last_processed_code_event_id_ = record.generic.order;
133 1816455 : return true;
134 : }
135 : return false;
136 : }
137 :
138 663657 : void ProfilerEventsProcessor::CodeEventHandler(
139 : const CodeEventsContainer& evt_rec) {
140 663657 : switch (evt_rec.generic.type) {
141 : case CodeEventRecord::CODE_CREATION:
142 : case CodeEventRecord::CODE_MOVE:
143 : case CodeEventRecord::CODE_DISABLE_OPT:
144 663648 : Enqueue(evt_rec);
145 663648 : break;
146 : case CodeEventRecord::CODE_DEOPT: {
147 : const CodeDeoptEventRecord* rec = &evt_rec.CodeDeoptEventRecord_;
148 9 : Address pc = rec->pc;
149 9 : int fp_to_sp_delta = rec->fp_to_sp_delta;
150 9 : Enqueue(evt_rec);
151 9 : AddDeoptStack(pc, fp_to_sp_delta);
152 9 : break;
153 : }
154 : case CodeEventRecord::NONE:
155 : case CodeEventRecord::REPORT_BUILTIN:
156 0 : UNREACHABLE();
157 : }
158 663657 : }
159 :
160 : ProfilerEventsProcessor::SampleProcessingResult
161 1951340 : SamplingEventsProcessor::ProcessOneSample() {
162 : TickSampleEventRecord record1;
163 3768020 : if (ticks_from_vm_buffer_.Peek(&record1) &&
164 1816680 : (record1.order == last_processed_code_event_id_)) {
165 : TickSampleEventRecord record;
166 994 : ticks_from_vm_buffer_.Dequeue(&record);
167 994 : generator_->RecordTickSample(record.sample);
168 : return OneSampleProcessed;
169 : }
170 :
171 1950454 : const TickSampleEventRecord* record = ticks_buffer_.Peek();
172 1950567 : if (record == nullptr) {
173 1176567 : if (ticks_from_vm_buffer_.IsEmpty()) return NoSamplesInQueue;
174 1108262 : return FoundSampleForNextCodeEvent;
175 : }
176 774000 : if (record->order != last_processed_code_event_id_) {
177 : return FoundSampleForNextCodeEvent;
178 : }
179 65871 : generator_->RecordTickSample(record->sample);
180 : ticks_buffer_.Remove();
181 65871 : return OneSampleProcessed;
182 : }
183 :
184 805 : void SamplingEventsProcessor::Run() {
185 805 : base::MutexGuard guard(&running_mutex_);
186 205946 : while (!!base::Relaxed_Load(&running_)) {
187 : base::TimeTicks nextSampleTime =
188 136224 : 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 488728 : do {
194 488728 : result = ProcessOneSample();
195 488729 : if (result == FoundSampleForNextCodeEvent) {
196 : // All ticks of the current last_processed_code_event_id_ are
197 : // processed, proceed to the next code event.
198 355611 : ProcessCodeEvent();
199 : }
200 488729 : now = base::TimeTicks::HighResolutionNow();
201 488728 : } while (result != NoSamplesInQueue && now < nextSampleTime);
202 :
203 68112 : 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 202023 : while (now < nextSampleTime &&
216 202023 : 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 182 : if (!base::Relaxed_Load(&running_)) {
221 : break;
222 : }
223 0 : now = base::TimeTicks::HighResolutionNow();
224 : }
225 : }
226 : }
227 :
228 : // Schedule next sample.
229 68112 : sampler_->DoSample();
230 : }
231 :
232 : // Process remaining tick events.
233 1461766 : do {
234 : SampleProcessingResult result;
235 : do {
236 1462855 : result = ProcessOneSample();
237 1462855 : } while (result == OneSampleProcessed);
238 1461766 : } while (ProcessCodeEvent());
239 805 : }
240 :
241 29 : void* SamplingEventsProcessor::operator new(size_t size) {
242 805 : return AlignedAlloc(size, alignof(SamplingEventsProcessor));
243 : }
244 :
245 800 : 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 155 : return static_cast<int>(profiles_->profiles()->size());
250 : }
251 :
252 :
253 44 : CpuProfile* CpuProfiler::GetProfile(int index) {
254 88 : 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 763 : void CpuProfiler::DeleteProfile(CpuProfile* profile) {
265 763 : profiles_->RemoveProfile(profile);
266 763 : if (profiles_->profiles()->empty() && !is_profiling_) {
267 : // If this was the last profile, clean up all accessory data as well.
268 633 : ResetProfiles();
269 : }
270 763 : }
271 :
272 : namespace {
273 :
274 265 : class CpuProfilersManager {
275 : public:
276 290 : void AddProfiler(Isolate* isolate, CpuProfiler* profiler) {
277 290 : base::MutexGuard lock(&mutex_);
278 : profilers_.emplace(isolate, profiler);
279 290 : }
280 :
281 290 : void RemoveProfiler(Isolate* isolate, CpuProfiler* profiler) {
282 290 : base::MutexGuard lock(&mutex_);
283 : auto range = profilers_.equal_range(isolate);
284 290 : for (auto it = range.first; it != range.second; ++it) {
285 290 : if (it->second != profiler) continue;
286 : profilers_.erase(it);
287 290 : return;
288 : }
289 0 : UNREACHABLE();
290 : }
291 :
292 10 : void CallCollectSample(Isolate* isolate) {
293 10 : base::MutexGuard lock(&mutex_);
294 : auto range = profilers_.equal_range(isolate);
295 20 : for (auto it = range.first; it != range.second; ++it) {
296 10 : it->second->CollectSample();
297 : }
298 10 : }
299 :
300 : private:
301 : std::unordered_multimap<Isolate*, CpuProfiler*> profilers_;
302 : base::Mutex mutex_;
303 : };
304 :
305 590 : DEFINE_LAZY_LEAKY_OBJECT_GETTER(CpuProfilersManager, GetProfilersManager)
306 :
307 : } // namespace
308 :
309 271 : CpuProfiler::CpuProfiler(Isolate* isolate)
310 271 : : CpuProfiler(isolate, new CpuProfilesCollection(isolate), nullptr,
311 542 : nullptr) {}
312 :
313 290 : 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 290 : FLAG_cpu_profiler_sampling_interval)),
319 : profiles_(test_profiles),
320 : generator_(test_generator),
321 : processor_(test_processor),
322 870 : is_profiling_(false) {
323 : profiles_->set_cpu_profiler(this);
324 290 : GetProfilersManager()->AddProfiler(isolate, this);
325 290 : }
326 :
327 580 : CpuProfiler::~CpuProfiler() {
328 : DCHECK(!is_profiling_);
329 290 : GetProfilersManager()->RemoveProfiler(isolate_, this);
330 290 : }
331 :
332 575 : void CpuProfiler::set_sampling_interval(base::TimeDelta value) {
333 : DCHECK(!is_profiling_);
334 575 : sampling_interval_ = value;
335 575 : }
336 :
337 683 : void CpuProfiler::ResetProfiles() {
338 683 : profiles_.reset(new CpuProfilesCollection(isolate_));
339 : profiles_->set_cpu_profiler(this);
340 : profiler_listener_.reset();
341 683 : generator_.reset();
342 683 : }
343 :
344 761 : void CpuProfiler::CreateEntriesForRuntimeCallStats() {
345 761 : RuntimeCallStats* rcs = isolate_->counters()->runtime_call_stats();
346 : CodeMap* code_map = generator_->code_map();
347 1744973 : for (int i = 0; i < RuntimeCallStats::kNumberOfCounters; ++i) {
348 : RuntimeCallCounter* counter = rcs->GetCounter(i);
349 : DCHECK(counter->name());
350 : auto entry = new CodeEntry(CodeEventListener::FUNCTION_TAG, counter->name(),
351 872106 : "native V8Runtime");
352 872106 : code_map->AddCode(reinterpret_cast<Address>(counter), entry, 1);
353 : }
354 761 : }
355 :
356 : // static
357 10 : void CpuProfiler::CollectSample(Isolate* isolate) {
358 10 : GetProfilersManager()->CallCollectSample(isolate);
359 10 : }
360 :
361 0 : void CpuProfiler::CollectSample() {
362 10 : if (processor_) {
363 10 : processor_->AddCurrentStack();
364 : }
365 0 : }
366 :
367 916 : void CpuProfiler::StartProfiling(const char* title, bool record_samples,
368 : ProfilingMode mode) {
369 1832 : if (profiles_->StartProfiling(title, record_samples, mode)) {
370 2748 : TRACE_EVENT0("v8", "CpuProfiler::StartProfiling");
371 916 : StartProcessorIfNotStarted();
372 : }
373 916 : }
374 :
375 841 : void CpuProfiler::StartProfiling(String title, bool record_samples,
376 : ProfilingMode mode) {
377 1682 : StartProfiling(profiles_->GetName(title), record_samples, mode);
378 1682 : isolate_->debug()->feature_tracker()->Track(DebugFeatureTracker::kProfiler);
379 841 : }
380 :
381 916 : void CpuProfiler::StartProcessorIfNotStarted() {
382 916 : if (processor_) {
383 140 : processor_->AddCurrentStack();
384 140 : return;
385 : }
386 776 : isolate_->wasm_engine()->EnableCodeLogging(isolate_);
387 776 : Logger* logger = isolate_->logger();
388 : // Disable logging when using the new implementation.
389 776 : saved_is_logging_ = logger->is_logging();
390 : logger->set_is_logging(false);
391 :
392 : bool codemap_needs_initialization = false;
393 776 : if (!generator_) {
394 761 : generator_.reset(new ProfileGenerator(profiles_.get()));
395 : codemap_needs_initialization = true;
396 761 : CreateEntriesForRuntimeCallStats();
397 : }
398 2328 : processor_.reset(new SamplingEventsProcessor(isolate_, generator_.get(),
399 776 : sampling_interval_));
400 776 : if (profiler_listener_) {
401 15 : profiler_listener_->set_observer(processor_.get());
402 : } else {
403 761 : profiler_listener_.reset(new ProfilerListener(isolate_, processor_.get()));
404 : }
405 776 : logger->AddCodeEventListener(profiler_listener_.get());
406 776 : is_profiling_ = true;
407 776 : isolate_->set_is_profiling(true);
408 : // Enumerate stuff we already have in the heap.
409 : DCHECK(isolate_->heap()->HasBeenSetUp());
410 776 : if (codemap_needs_initialization) {
411 761 : if (!FLAG_prof_browser_mode) {
412 25 : logger->LogCodeObjects();
413 : }
414 761 : logger->LogCompiledFunctions();
415 761 : logger->LogAccessorCallbacks();
416 761 : LogBuiltins();
417 : }
418 : // Enable stack sampling.
419 776 : processor_->AddCurrentStack();
420 776 : processor_->StartSynchronously();
421 : }
422 :
423 871 : CpuProfile* CpuProfiler::StopProfiling(const char* title) {
424 871 : if (!is_profiling_) return nullptr;
425 871 : StopProcessorIfLastProfile(title);
426 871 : return profiles_->StopProfiling(title);
427 : }
428 :
429 806 : CpuProfile* CpuProfiler::StopProfiling(String title) {
430 806 : return StopProfiling(profiles_->GetName(title));
431 : }
432 :
433 871 : void CpuProfiler::StopProcessorIfLastProfile(const char* title) {
434 871 : if (!profiles_->IsLastProfile(title)) return;
435 741 : StopProcessor();
436 : }
437 :
438 776 : void CpuProfiler::StopProcessor() {
439 776 : Logger* logger = isolate_->logger();
440 776 : is_profiling_ = false;
441 : isolate_->set_is_profiling(false);
442 776 : logger->RemoveCodeEventListener(profiler_listener_.get());
443 776 : processor_->StopSynchronously();
444 : processor_.reset();
445 776 : logger->set_is_logging(saved_is_logging_);
446 776 : }
447 :
448 :
449 761 : void CpuProfiler::LogBuiltins() {
450 761 : Builtins* builtins = isolate_->builtins();
451 : DCHECK(builtins->is_initialized());
452 2306591 : 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 2305830 : rec->instruction_start = builtins->builtin(id)->InstructionStart();
457 1152915 : rec->builtin_id = id;
458 1152915 : processor_->Enqueue(evt_rec);
459 : }
460 761 : }
461 :
462 : } // namespace internal
463 120216 : } // namespace v8
|
