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