1 // Copyright 2010 the V8 project authors. All rights reserved.
2 // Redistribution and use in source and binary forms, with or without
3 // modification, are permitted provided that the following conditions are
4 // met:
5 //
6 // * Redistributions of source code must retain the above copyright
7 // notice, this list of conditions and the following disclaimer.
8 // * Redistributions in binary form must reproduce the above
9 // copyright notice, this list of conditions and the following
10 // disclaimer in the documentation and/or other materials provided
11 // with the distribution.
12 // * Neither the name of Google Inc. nor the names of its
13 // contributors may be used to endorse or promote products derived
14 // from this software without specific prior written permission.
15 //
16 // THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
17 // "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
18 // LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
19 // A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
20 // OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
21 // SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
22 // LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
23 // DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
24 // THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
25 // (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
26 // OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
27 //
28 // Tests of profiles generator and utilities.
29
30 #include "src/v8.h"
31
32 #include "include/v8-profiler.h"
33 #include "src/base/platform/platform.h"
34 #include "src/deoptimizer.h"
35 #include "src/profiler/cpu-profiler-inl.h"
36 #include "src/profiler/profiler-listener.h"
37 #include "src/utils.h"
38 #include "test/cctest/cctest.h"
39 #include "test/cctest/profiler-extension.h"
40
41 using i::CodeEntry;
42 using i::CpuProfile;
43 using i::CpuProfiler;
44 using i::CpuProfilesCollection;
45 using i::Heap;
46 using i::ProfileGenerator;
47 using i::ProfileNode;
48 using i::ProfilerEventsProcessor;
49 using i::ProfilerListener;
50 using i::ScopedVector;
51 using i::Vector;
52
53 // Helper methods
GetFunction(v8::Local<v8::Context> env,const char * name)54 static v8::Local<v8::Function> GetFunction(v8::Local<v8::Context> env,
55 const char* name) {
56 return v8::Local<v8::Function>::Cast(
57 env->Global()->Get(env, v8_str(name)).ToLocalChecked());
58 }
59
offset(const char * src,const char * substring)60 static size_t offset(const char* src, const char* substring) {
61 const char* it = strstr(src, substring);
62 CHECK(it);
63 return static_cast<size_t>(it - src);
64 }
65
reason(const i::Deoptimizer::DeoptReason reason)66 static const char* reason(const i::Deoptimizer::DeoptReason reason) {
67 return i::Deoptimizer::GetDeoptReason(reason);
68 }
69
TEST(StartStop)70 TEST(StartStop) {
71 CpuProfilesCollection profiles(CcTest::i_isolate());
72 ProfileGenerator generator(&profiles);
73 std::unique_ptr<ProfilerEventsProcessor> processor(
74 new ProfilerEventsProcessor(&generator, nullptr,
75 v8::base::TimeDelta::FromMicroseconds(100)));
76 processor->Start();
77 processor->StopSynchronously();
78 }
79
EnqueueTickSampleEvent(ProfilerEventsProcessor * proc,i::Address frame1,i::Address frame2=NULL,i::Address frame3=NULL)80 static void EnqueueTickSampleEvent(ProfilerEventsProcessor* proc,
81 i::Address frame1,
82 i::Address frame2 = NULL,
83 i::Address frame3 = NULL) {
84 i::TickSample* sample = proc->StartTickSample();
85 sample->pc = frame1;
86 sample->tos = frame1;
87 sample->frames_count = 0;
88 if (frame2 != NULL) {
89 sample->stack[0] = frame2;
90 sample->frames_count = 1;
91 }
92 if (frame3 != NULL) {
93 sample->stack[1] = frame3;
94 sample->frames_count = 2;
95 }
96 proc->FinishTickSample();
97 }
98
99 namespace {
100
101 class TestSetup {
102 public:
TestSetup()103 TestSetup()
104 : old_flag_prof_browser_mode_(i::FLAG_prof_browser_mode) {
105 i::FLAG_prof_browser_mode = false;
106 }
107
~TestSetup()108 ~TestSetup() {
109 i::FLAG_prof_browser_mode = old_flag_prof_browser_mode_;
110 }
111
112 private:
113 bool old_flag_prof_browser_mode_;
114 };
115
116 } // namespace
117
CreateCode(LocalContext * env)118 i::AbstractCode* CreateCode(LocalContext* env) {
119 static int counter = 0;
120 i::EmbeddedVector<char, 256> script;
121 i::EmbeddedVector<char, 32> name;
122
123 i::SNPrintF(name, "function_%d", ++counter);
124 const char* name_start = name.start();
125 i::SNPrintF(script,
126 "function %s() {\n"
127 "var counter = 0;\n"
128 "for (var i = 0; i < %d; ++i) counter += i;\n"
129 "return '%s_' + counter;\n"
130 "}\n"
131 "%s();\n", name_start, counter, name_start, name_start);
132 CompileRun(script.start());
133
134 i::Handle<i::JSFunction> fun = i::Handle<i::JSFunction>::cast(
135 v8::Utils::OpenHandle(*GetFunction(env->local(), name_start)));
136 return fun->abstract_code();
137 }
138
TEST(CodeEvents)139 TEST(CodeEvents) {
140 CcTest::InitializeVM();
141 LocalContext env;
142 i::Isolate* isolate = CcTest::i_isolate();
143 i::Factory* factory = isolate->factory();
144 TestSetup test_setup;
145
146 i::HandleScope scope(isolate);
147
148 i::AbstractCode* aaa_code = CreateCode(&env);
149 i::AbstractCode* comment_code = CreateCode(&env);
150 i::AbstractCode* args5_code = CreateCode(&env);
151 i::AbstractCode* comment2_code = CreateCode(&env);
152 i::AbstractCode* moved_code = CreateCode(&env);
153 i::AbstractCode* args3_code = CreateCode(&env);
154 i::AbstractCode* args4_code = CreateCode(&env);
155
156 CpuProfilesCollection* profiles = new CpuProfilesCollection(isolate);
157 ProfileGenerator* generator = new ProfileGenerator(profiles);
158 ProfilerEventsProcessor* processor = new ProfilerEventsProcessor(
159 generator, nullptr, v8::base::TimeDelta::FromMicroseconds(100));
160 CpuProfiler profiler(isolate, profiles, generator, processor);
161 profiles->StartProfiling("", false);
162 processor->Start();
163 ProfilerListener profiler_listener(isolate);
164 isolate->code_event_dispatcher()->AddListener(&profiler_listener);
165 profiler_listener.AddObserver(&profiler);
166
167 // Enqueue code creation events.
168 const char* aaa_str = "aaa";
169 i::Handle<i::String> aaa_name = factory->NewStringFromAsciiChecked(aaa_str);
170 profiler_listener.CodeCreateEvent(i::Logger::FUNCTION_TAG, aaa_code,
171 *aaa_name);
172 profiler_listener.CodeCreateEvent(i::Logger::BUILTIN_TAG, comment_code,
173 "comment");
174 profiler_listener.CodeCreateEvent(i::Logger::STUB_TAG, args5_code, 5);
175 profiler_listener.CodeCreateEvent(i::Logger::BUILTIN_TAG, comment2_code,
176 "comment2");
177 profiler_listener.CodeMoveEvent(comment2_code, moved_code->address());
178 profiler_listener.CodeCreateEvent(i::Logger::STUB_TAG, args3_code, 3);
179 profiler_listener.CodeCreateEvent(i::Logger::STUB_TAG, args4_code, 4);
180
181 // Enqueue a tick event to enable code events processing.
182 EnqueueTickSampleEvent(processor, aaa_code->address());
183
184 profiler_listener.RemoveObserver(&profiler);
185 isolate->code_event_dispatcher()->RemoveListener(&profiler_listener);
186 processor->StopSynchronously();
187
188 // Check the state of profile generator.
189 CodeEntry* aaa = generator->code_map()->FindEntry(aaa_code->address());
190 CHECK(aaa);
191 CHECK_EQ(0, strcmp(aaa_str, aaa->name()));
192
193 CodeEntry* comment =
194 generator->code_map()->FindEntry(comment_code->address());
195 CHECK(comment);
196 CHECK_EQ(0, strcmp("comment", comment->name()));
197
198 CodeEntry* args5 = generator->code_map()->FindEntry(args5_code->address());
199 CHECK(args5);
200 CHECK_EQ(0, strcmp("5", args5->name()));
201
202 CHECK(!generator->code_map()->FindEntry(comment2_code->address()));
203
204 CodeEntry* comment2 = generator->code_map()->FindEntry(moved_code->address());
205 CHECK(comment2);
206 CHECK_EQ(0, strcmp("comment2", comment2->name()));
207 }
208
209 template<typename T>
CompareProfileNodes(const T * p1,const T * p2)210 static int CompareProfileNodes(const T* p1, const T* p2) {
211 return strcmp((*p1)->entry()->name(), (*p2)->entry()->name());
212 }
213
TEST(TickEvents)214 TEST(TickEvents) {
215 TestSetup test_setup;
216 LocalContext env;
217 i::Isolate* isolate = CcTest::i_isolate();
218 i::HandleScope scope(isolate);
219
220 i::AbstractCode* frame1_code = CreateCode(&env);
221 i::AbstractCode* frame2_code = CreateCode(&env);
222 i::AbstractCode* frame3_code = CreateCode(&env);
223
224 CpuProfilesCollection* profiles = new CpuProfilesCollection(isolate);
225 ProfileGenerator* generator = new ProfileGenerator(profiles);
226 ProfilerEventsProcessor* processor = new ProfilerEventsProcessor(
227 generator, nullptr, v8::base::TimeDelta::FromMicroseconds(100));
228 CpuProfiler profiler(isolate, profiles, generator, processor);
229 profiles->StartProfiling("", false);
230 processor->Start();
231 ProfilerListener profiler_listener(isolate);
232 isolate->code_event_dispatcher()->AddListener(&profiler_listener);
233 profiler_listener.AddObserver(&profiler);
234
235 profiler_listener.CodeCreateEvent(i::Logger::BUILTIN_TAG, frame1_code, "bbb");
236 profiler_listener.CodeCreateEvent(i::Logger::STUB_TAG, frame2_code, 5);
237 profiler_listener.CodeCreateEvent(i::Logger::BUILTIN_TAG, frame3_code, "ddd");
238
239 EnqueueTickSampleEvent(processor, frame1_code->instruction_start());
240 EnqueueTickSampleEvent(
241 processor,
242 frame2_code->instruction_start() + frame2_code->ExecutableSize() / 2,
243 frame1_code->instruction_start() + frame2_code->ExecutableSize() / 2);
244 EnqueueTickSampleEvent(processor, frame3_code->instruction_end() - 1,
245 frame2_code->instruction_end() - 1,
246 frame1_code->instruction_end() - 1);
247
248 profiler_listener.RemoveObserver(&profiler);
249 isolate->code_event_dispatcher()->RemoveListener(&profiler_listener);
250 processor->StopSynchronously();
251 CpuProfile* profile = profiles->StopProfiling("");
252 CHECK(profile);
253
254 // Check call trees.
255 const i::List<ProfileNode*>* top_down_root_children =
256 profile->top_down()->root()->children();
257 CHECK_EQ(1, top_down_root_children->length());
258 CHECK_EQ(0, strcmp("bbb", top_down_root_children->last()->entry()->name()));
259 const i::List<ProfileNode*>* top_down_bbb_children =
260 top_down_root_children->last()->children();
261 CHECK_EQ(1, top_down_bbb_children->length());
262 CHECK_EQ(0, strcmp("5", top_down_bbb_children->last()->entry()->name()));
263 const i::List<ProfileNode*>* top_down_stub_children =
264 top_down_bbb_children->last()->children();
265 CHECK_EQ(1, top_down_stub_children->length());
266 CHECK_EQ(0, strcmp("ddd", top_down_stub_children->last()->entry()->name()));
267 const i::List<ProfileNode*>* top_down_ddd_children =
268 top_down_stub_children->last()->children();
269 CHECK_EQ(0, top_down_ddd_children->length());
270
271 isolate->code_event_dispatcher()->RemoveListener(&profiler_listener);
272 }
273
274 // http://crbug/51594
275 // This test must not crash.
TEST(CrashIfStoppingLastNonExistentProfile)276 TEST(CrashIfStoppingLastNonExistentProfile) {
277 CcTest::InitializeVM();
278 TestSetup test_setup;
279 CpuProfiler* profiler = CcTest::i_isolate()->cpu_profiler();
280 profiler->StartProfiling("1");
281 profiler->StopProfiling("2");
282 profiler->StartProfiling("1");
283 profiler->StopProfiling("");
284 }
285
286 // http://code.google.com/p/v8/issues/detail?id=1398
287 // Long stacks (exceeding max frames limit) must not be erased.
TEST(Issue1398)288 TEST(Issue1398) {
289 TestSetup test_setup;
290 LocalContext env;
291 i::Isolate* isolate = CcTest::i_isolate();
292 i::HandleScope scope(isolate);
293
294 i::AbstractCode* code = CreateCode(&env);
295
296 CpuProfilesCollection* profiles = new CpuProfilesCollection(isolate);
297 ProfileGenerator* generator = new ProfileGenerator(profiles);
298 ProfilerEventsProcessor* processor = new ProfilerEventsProcessor(
299 generator, nullptr, v8::base::TimeDelta::FromMicroseconds(100));
300 CpuProfiler profiler(isolate, profiles, generator, processor);
301 profiles->StartProfiling("", false);
302 processor->Start();
303 ProfilerListener profiler_listener(isolate);
304 isolate->code_event_dispatcher()->AddListener(&profiler_listener);
305 profiler_listener.AddObserver(&profiler);
306
307 profiler_listener.CodeCreateEvent(i::Logger::BUILTIN_TAG, code, "bbb");
308
309 i::TickSample* sample = processor->StartTickSample();
310 sample->pc = code->address();
311 sample->tos = 0;
312 sample->frames_count = i::TickSample::kMaxFramesCount;
313 for (unsigned i = 0; i < sample->frames_count; ++i) {
314 sample->stack[i] = code->address();
315 }
316 processor->FinishTickSample();
317
318 profiler_listener.RemoveObserver(&profiler);
319 isolate->code_event_dispatcher()->RemoveListener(&profiler_listener);
320 processor->StopSynchronously();
321 CpuProfile* profile = profiles->StopProfiling("");
322 CHECK(profile);
323
324 unsigned actual_depth = 0;
325 const ProfileNode* node = profile->top_down()->root();
326 while (node->children()->length() > 0) {
327 node = node->children()->last();
328 ++actual_depth;
329 }
330
331 CHECK_EQ(1 + i::TickSample::kMaxFramesCount, actual_depth); // +1 for PC.
332 }
333
TEST(DeleteAllCpuProfiles)334 TEST(DeleteAllCpuProfiles) {
335 CcTest::InitializeVM();
336 TestSetup test_setup;
337 CpuProfiler* profiler = CcTest::i_isolate()->cpu_profiler();
338 CHECK_EQ(0, profiler->GetProfilesCount());
339 profiler->DeleteAllProfiles();
340 CHECK_EQ(0, profiler->GetProfilesCount());
341
342 profiler->StartProfiling("1");
343 profiler->StopProfiling("1");
344 CHECK_EQ(1, profiler->GetProfilesCount());
345 profiler->DeleteAllProfiles();
346 CHECK_EQ(0, profiler->GetProfilesCount());
347 profiler->StartProfiling("1");
348 profiler->StartProfiling("2");
349 profiler->StopProfiling("2");
350 profiler->StopProfiling("1");
351 CHECK_EQ(2, profiler->GetProfilesCount());
352 profiler->DeleteAllProfiles();
353 CHECK_EQ(0, profiler->GetProfilesCount());
354
355 // Test profiling cancellation by the 'delete' command.
356 profiler->StartProfiling("1");
357 profiler->StartProfiling("2");
358 CHECK_EQ(0, profiler->GetProfilesCount());
359 profiler->DeleteAllProfiles();
360 CHECK_EQ(0, profiler->GetProfilesCount());
361 }
362
363
FindCpuProfile(v8::CpuProfiler * v8profiler,const v8::CpuProfile * v8profile)364 static bool FindCpuProfile(v8::CpuProfiler* v8profiler,
365 const v8::CpuProfile* v8profile) {
366 i::CpuProfiler* profiler = reinterpret_cast<i::CpuProfiler*>(v8profiler);
367 const i::CpuProfile* profile =
368 reinterpret_cast<const i::CpuProfile*>(v8profile);
369 int length = profiler->GetProfilesCount();
370 for (int i = 0; i < length; i++) {
371 if (profile == profiler->GetProfile(i))
372 return true;
373 }
374 return false;
375 }
376
377
TEST(DeleteCpuProfile)378 TEST(DeleteCpuProfile) {
379 LocalContext env;
380 v8::HandleScope scope(env->GetIsolate());
381 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler();
382 i::CpuProfiler* iprofiler = reinterpret_cast<i::CpuProfiler*>(cpu_profiler);
383
384 CHECK_EQ(0, iprofiler->GetProfilesCount());
385 v8::Local<v8::String> name1 = v8_str("1");
386 cpu_profiler->StartProfiling(name1);
387 v8::CpuProfile* p1 = cpu_profiler->StopProfiling(name1);
388 CHECK(p1);
389 CHECK_EQ(1, iprofiler->GetProfilesCount());
390 CHECK(FindCpuProfile(cpu_profiler, p1));
391 p1->Delete();
392 CHECK_EQ(0, iprofiler->GetProfilesCount());
393
394 v8::Local<v8::String> name2 = v8_str("2");
395 cpu_profiler->StartProfiling(name2);
396 v8::CpuProfile* p2 = cpu_profiler->StopProfiling(name2);
397 CHECK(p2);
398 CHECK_EQ(1, iprofiler->GetProfilesCount());
399 CHECK(FindCpuProfile(cpu_profiler, p2));
400 v8::Local<v8::String> name3 = v8_str("3");
401 cpu_profiler->StartProfiling(name3);
402 v8::CpuProfile* p3 = cpu_profiler->StopProfiling(name3);
403 CHECK(p3);
404 CHECK_EQ(2, iprofiler->GetProfilesCount());
405 CHECK_NE(p2, p3);
406 CHECK(FindCpuProfile(cpu_profiler, p3));
407 CHECK(FindCpuProfile(cpu_profiler, p2));
408 p2->Delete();
409 CHECK_EQ(1, iprofiler->GetProfilesCount());
410 CHECK(!FindCpuProfile(cpu_profiler, p2));
411 CHECK(FindCpuProfile(cpu_profiler, p3));
412 p3->Delete();
413 CHECK_EQ(0, iprofiler->GetProfilesCount());
414 }
415
416
TEST(ProfileStartEndTime)417 TEST(ProfileStartEndTime) {
418 LocalContext env;
419 v8::HandleScope scope(env->GetIsolate());
420 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler();
421
422 v8::Local<v8::String> profile_name = v8_str("test");
423 cpu_profiler->StartProfiling(profile_name);
424 const v8::CpuProfile* profile = cpu_profiler->StopProfiling(profile_name);
425 CHECK(profile->GetStartTime() <= profile->GetEndTime());
426 }
427
RunProfiler(v8::Local<v8::Context> env,v8::Local<v8::Function> function,v8::Local<v8::Value> argv[],int argc,unsigned min_js_samples=0,unsigned min_external_samples=0,bool collect_samples=false)428 static v8::CpuProfile* RunProfiler(v8::Local<v8::Context> env,
429 v8::Local<v8::Function> function,
430 v8::Local<v8::Value> argv[], int argc,
431 unsigned min_js_samples = 0,
432 unsigned min_external_samples = 0,
433 bool collect_samples = false) {
434 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler();
435 v8::Local<v8::String> profile_name = v8_str("my_profile");
436
437 cpu_profiler->SetSamplingInterval(100);
438 cpu_profiler->StartProfiling(profile_name, collect_samples);
439
440 v8::sampler::Sampler* sampler =
441 reinterpret_cast<i::Isolate*>(env->GetIsolate())->logger()->sampler();
442 sampler->StartCountingSamples();
443 do {
444 function->Call(env, env->Global(), argc, argv).ToLocalChecked();
445 } while (sampler->js_sample_count() < min_js_samples ||
446 sampler->external_sample_count() < min_external_samples);
447
448 v8::CpuProfile* profile = cpu_profiler->StopProfiling(profile_name);
449
450 CHECK(profile);
451 // Dump collected profile to have a better diagnostic in case of failure.
452 reinterpret_cast<i::CpuProfile*>(profile)->Print();
453
454 return profile;
455 }
456
457
FindChild(v8::Local<v8::Context> context,const v8::CpuProfileNode * node,const char * name)458 static const v8::CpuProfileNode* FindChild(v8::Local<v8::Context> context,
459 const v8::CpuProfileNode* node,
460 const char* name) {
461 int count = node->GetChildrenCount();
462 v8::Local<v8::String> name_handle = v8_str(name);
463 for (int i = 0; i < count; i++) {
464 const v8::CpuProfileNode* child = node->GetChild(i);
465 if (name_handle->Equals(context, child->GetFunctionName()).FromJust()) {
466 return child;
467 }
468 }
469 return NULL;
470 }
471
472
GetChild(v8::Local<v8::Context> context,const v8::CpuProfileNode * node,const char * name)473 static const v8::CpuProfileNode* GetChild(v8::Local<v8::Context> context,
474 const v8::CpuProfileNode* node,
475 const char* name) {
476 const v8::CpuProfileNode* result = FindChild(context, node, name);
477 if (!result) {
478 char buffer[100];
479 i::SNPrintF(i::ArrayVector(buffer), "Failed to GetChild: %s", name);
480 FATAL(buffer);
481 }
482 return result;
483 }
484
485
CheckSimpleBranch(v8::Local<v8::Context> context,const v8::CpuProfileNode * node,const char * names[],int length)486 static void CheckSimpleBranch(v8::Local<v8::Context> context,
487 const v8::CpuProfileNode* node,
488 const char* names[], int length) {
489 for (int i = 0; i < length; i++) {
490 const char* name = names[i];
491 node = GetChild(context, node, name);
492 }
493 }
494
495
GetSimpleBranch(v8::Local<v8::Context> context,v8::CpuProfile * profile,const char * names[],int length)496 static const ProfileNode* GetSimpleBranch(v8::Local<v8::Context> context,
497 v8::CpuProfile* profile,
498 const char* names[], int length) {
499 const v8::CpuProfileNode* node = profile->GetTopDownRoot();
500 for (int i = 0; i < length; i++) {
501 node = GetChild(context, node, names[i]);
502 }
503 return reinterpret_cast<const ProfileNode*>(node);
504 }
505
CallCollectSample(const v8::FunctionCallbackInfo<v8::Value> & info)506 static void CallCollectSample(const v8::FunctionCallbackInfo<v8::Value>& info) {
507 info.GetIsolate()->GetCpuProfiler()->CollectSample();
508 }
509
510 static const char* cpu_profiler_test_source =
511 "%NeverOptimizeFunction(loop);\n"
512 "%NeverOptimizeFunction(delay);\n"
513 "%NeverOptimizeFunction(bar);\n"
514 "%NeverOptimizeFunction(baz);\n"
515 "%NeverOptimizeFunction(foo);\n"
516 "%NeverOptimizeFunction(start);\n"
517 "function loop(timeout) {\n"
518 " this.mmm = 0;\n"
519 " var start = Date.now();\n"
520 " do {\n"
521 " var n = 1000;\n"
522 " while(n > 1) {\n"
523 " n--;\n"
524 " this.mmm += n * n * n;\n"
525 " }\n"
526 " } while (Date.now() - start < timeout);\n"
527 "}\n"
528 "function delay() { loop(10); }\n"
529 "function bar() { delay(); }\n"
530 "function baz() { delay(); }\n"
531 "function foo() {\n"
532 " delay();\n"
533 " bar();\n"
534 " delay();\n"
535 " baz();\n"
536 "}\n"
537 "function start(duration) {\n"
538 " var start = Date.now();\n"
539 " do {\n"
540 " foo();\n"
541 " } while (Date.now() - start < duration);\n"
542 "}\n";
543
544 // Check that the profile tree for the script above will look like the
545 // following:
546 //
547 // [Top down]:
548 // 1062 0 (root) [-1]
549 // 1054 0 start [-1]
550 // 1054 1 foo [-1]
551 // 265 0 baz [-1]
552 // 265 1 delay [-1]
553 // 264 264 loop [-1]
554 // 525 3 delay [-1]
555 // 522 522 loop [-1]
556 // 263 0 bar [-1]
557 // 263 1 delay [-1]
558 // 262 262 loop [-1]
559 // 2 2 (program) [-1]
560 // 6 6 (garbage collector) [-1]
TEST(CollectCpuProfile)561 TEST(CollectCpuProfile) {
562 i::FLAG_allow_natives_syntax = true;
563 LocalContext env;
564 v8::HandleScope scope(env->GetIsolate());
565
566 CompileRun(cpu_profiler_test_source);
567 v8::Local<v8::Function> function = GetFunction(env.local(), "start");
568
569 int32_t profiling_interval_ms = 200;
570 v8::Local<v8::Value> args[] = {
571 v8::Integer::New(env->GetIsolate(), profiling_interval_ms)};
572 v8::CpuProfile* profile =
573 RunProfiler(env.local(), function, args, arraysize(args), 1000);
574
575 const v8::CpuProfileNode* root = profile->GetTopDownRoot();
576 const v8::CpuProfileNode* start_node = GetChild(env.local(), root, "start");
577 const v8::CpuProfileNode* foo_node = GetChild(env.local(), start_node, "foo");
578
579 const char* bar_branch[] = {"bar", "delay", "loop"};
580 CheckSimpleBranch(env.local(), foo_node, bar_branch, arraysize(bar_branch));
581 const char* baz_branch[] = {"baz", "delay", "loop"};
582 CheckSimpleBranch(env.local(), foo_node, baz_branch, arraysize(baz_branch));
583 const char* delay_branch[] = {"delay", "loop"};
584 CheckSimpleBranch(env.local(), foo_node, delay_branch,
585 arraysize(delay_branch));
586
587 profile->Delete();
588 }
589
590 static const char* hot_deopt_no_frame_entry_test_source =
591 "%NeverOptimizeFunction(foo);\n"
592 "%NeverOptimizeFunction(start);\n"
593 "function foo(a, b) {\n"
594 " return a + b;\n"
595 "}\n"
596 "function start(timeout) {\n"
597 " var start = Date.now();\n"
598 " do {\n"
599 " for (var i = 1; i < 1000; ++i) foo(1, i);\n"
600 " var duration = Date.now() - start;\n"
601 " } while (duration < timeout);\n"
602 " return duration;\n"
603 "}\n";
604
605 // Check that the profile tree for the script above will look like the
606 // following:
607 //
608 // [Top down]:
609 // 1062 0 (root) [-1]
610 // 1054 0 start [-1]
611 // 1054 1 foo [-1]
612 // 2 2 (program) [-1]
613 // 6 6 (garbage collector) [-1]
614 //
615 // The test checks no FP ranges are present in a deoptimized function.
616 // If 'foo' has no ranges the samples falling into the prologue will miss the
617 // 'start' function on the stack, so 'foo' will be attached to the (root).
TEST(HotDeoptNoFrameEntry)618 TEST(HotDeoptNoFrameEntry) {
619 i::FLAG_allow_natives_syntax = true;
620 LocalContext env;
621 v8::HandleScope scope(env->GetIsolate());
622
623 CompileRun(hot_deopt_no_frame_entry_test_source);
624 v8::Local<v8::Function> function = GetFunction(env.local(), "start");
625
626 int32_t profiling_interval_ms = 200;
627 v8::Local<v8::Value> args[] = {
628 v8::Integer::New(env->GetIsolate(), profiling_interval_ms)};
629 v8::CpuProfile* profile =
630 RunProfiler(env.local(), function, args, arraysize(args), 1000);
631 function->Call(env.local(), env->Global(), arraysize(args), args)
632 .ToLocalChecked();
633
634 const v8::CpuProfileNode* root = profile->GetTopDownRoot();
635 const v8::CpuProfileNode* start_node = GetChild(env.local(), root, "start");
636 GetChild(env.local(), start_node, "foo");
637
638 profile->Delete();
639 }
640
TEST(CollectCpuProfileSamples)641 TEST(CollectCpuProfileSamples) {
642 i::FLAG_allow_natives_syntax = true;
643 LocalContext env;
644 v8::HandleScope scope(env->GetIsolate());
645
646 CompileRun(cpu_profiler_test_source);
647 v8::Local<v8::Function> function = GetFunction(env.local(), "start");
648
649 int32_t profiling_interval_ms = 200;
650 v8::Local<v8::Value> args[] = {
651 v8::Integer::New(env->GetIsolate(), profiling_interval_ms)};
652 v8::CpuProfile* profile =
653 RunProfiler(env.local(), function, args, arraysize(args), 1000, 0, true);
654
655 CHECK_LE(200, profile->GetSamplesCount());
656 uint64_t end_time = profile->GetEndTime();
657 uint64_t current_time = profile->GetStartTime();
658 CHECK_LE(current_time, end_time);
659 for (int i = 0; i < profile->GetSamplesCount(); i++) {
660 CHECK(profile->GetSample(i));
661 uint64_t timestamp = profile->GetSampleTimestamp(i);
662 CHECK_LE(current_time, timestamp);
663 CHECK_LE(timestamp, end_time);
664 current_time = timestamp;
665 }
666
667 profile->Delete();
668 }
669
670 static const char* cpu_profiler_test_source2 =
671 "%NeverOptimizeFunction(loop);\n"
672 "%NeverOptimizeFunction(delay);\n"
673 "%NeverOptimizeFunction(start);\n"
674 "function loop() {}\n"
675 "function delay() { loop(); }\n"
676 "function start(duration) {\n"
677 " var start = Date.now();\n"
678 " do {\n"
679 " for (var i = 0; i < 10000; ++i) delay();\n"
680 " } while (Date.now() - start < duration);\n"
681 "}";
682
683 // Check that the profile tree doesn't contain unexpected traces:
684 // - 'loop' can be called only by 'delay'
685 // - 'delay' may be called only by 'start'
686 // The profile will look like the following:
687 //
688 // [Top down]:
689 // 135 0 (root) [-1] #1
690 // 121 72 start [-1] #3
691 // 49 33 delay [-1] #4
692 // 16 16 loop [-1] #5
693 // 14 14 (program) [-1] #2
TEST(SampleWhenFrameIsNotSetup)694 TEST(SampleWhenFrameIsNotSetup) {
695 i::FLAG_allow_natives_syntax = true;
696 LocalContext env;
697 v8::HandleScope scope(env->GetIsolate());
698
699 CompileRun(cpu_profiler_test_source2);
700 v8::Local<v8::Function> function = GetFunction(env.local(), "start");
701
702 int32_t duration_ms = 100;
703 v8::Local<v8::Value> args[] = {
704 v8::Integer::New(env->GetIsolate(), duration_ms)};
705 v8::CpuProfile* profile =
706 RunProfiler(env.local(), function, args, arraysize(args), 1000);
707
708 const v8::CpuProfileNode* root = profile->GetTopDownRoot();
709 const v8::CpuProfileNode* start_node = GetChild(env.local(), root, "start");
710 const v8::CpuProfileNode* delay_node =
711 GetChild(env.local(), start_node, "delay");
712 GetChild(env.local(), delay_node, "loop");
713
714 profile->Delete();
715 }
716
717 static const char* native_accessor_test_source = "function start(count) {\n"
718 " for (var i = 0; i < count; i++) {\n"
719 " var o = instance.foo;\n"
720 " instance.foo = o + 1;\n"
721 " }\n"
722 "}\n";
723
724 class TestApiCallbacks {
725 public:
TestApiCallbacks(int min_duration_ms)726 explicit TestApiCallbacks(int min_duration_ms)
727 : min_duration_ms_(min_duration_ms),
728 is_warming_up_(false) {}
729
Getter(v8::Local<v8::String> name,const v8::PropertyCallbackInfo<v8::Value> & info)730 static void Getter(v8::Local<v8::String> name,
731 const v8::PropertyCallbackInfo<v8::Value>& info) {
732 TestApiCallbacks* data = FromInfo(info);
733 data->Wait();
734 }
735
Setter(v8::Local<v8::String> name,v8::Local<v8::Value> value,const v8::PropertyCallbackInfo<void> & info)736 static void Setter(v8::Local<v8::String> name,
737 v8::Local<v8::Value> value,
738 const v8::PropertyCallbackInfo<void>& info) {
739 TestApiCallbacks* data = FromInfo(info);
740 data->Wait();
741 }
742
Callback(const v8::FunctionCallbackInfo<v8::Value> & info)743 static void Callback(const v8::FunctionCallbackInfo<v8::Value>& info) {
744 TestApiCallbacks* data = FromInfo(info);
745 data->Wait();
746 }
747
set_warming_up(bool value)748 void set_warming_up(bool value) { is_warming_up_ = value; }
749
750 private:
Wait()751 void Wait() {
752 if (is_warming_up_) return;
753 double start = v8::base::OS::TimeCurrentMillis();
754 double duration = 0;
755 while (duration < min_duration_ms_) {
756 v8::base::OS::Sleep(v8::base::TimeDelta::FromMilliseconds(1));
757 duration = v8::base::OS::TimeCurrentMillis() - start;
758 }
759 }
760
761 template <typename T>
FromInfo(const T & info)762 static TestApiCallbacks* FromInfo(const T& info) {
763 void* data = v8::External::Cast(*info.Data())->Value();
764 return reinterpret_cast<TestApiCallbacks*>(data);
765 }
766
767 int min_duration_ms_;
768 bool is_warming_up_;
769 };
770
771
772 // Test that native accessors are properly reported in the CPU profile.
773 // This test checks the case when the long-running accessors are called
774 // only once and the optimizer doesn't have chance to change the invocation
775 // code.
TEST(NativeAccessorUninitializedIC)776 TEST(NativeAccessorUninitializedIC) {
777 LocalContext env;
778 v8::Isolate* isolate = env->GetIsolate();
779 v8::HandleScope scope(isolate);
780
781 v8::Local<v8::FunctionTemplate> func_template =
782 v8::FunctionTemplate::New(isolate);
783 v8::Local<v8::ObjectTemplate> instance_template =
784 func_template->InstanceTemplate();
785
786 TestApiCallbacks accessors(100);
787 v8::Local<v8::External> data =
788 v8::External::New(isolate, &accessors);
789 instance_template->SetAccessor(v8_str("foo"), &TestApiCallbacks::Getter,
790 &TestApiCallbacks::Setter, data);
791 v8::Local<v8::Function> func =
792 func_template->GetFunction(env.local()).ToLocalChecked();
793 v8::Local<v8::Object> instance =
794 func->NewInstance(env.local()).ToLocalChecked();
795 env->Global()->Set(env.local(), v8_str("instance"), instance).FromJust();
796
797 CompileRun(native_accessor_test_source);
798 v8::Local<v8::Function> function = GetFunction(env.local(), "start");
799
800 int32_t repeat_count = 1;
801 v8::Local<v8::Value> args[] = {v8::Integer::New(isolate, repeat_count)};
802 v8::CpuProfile* profile =
803 RunProfiler(env.local(), function, args, arraysize(args), 0, 100);
804
805 const v8::CpuProfileNode* root = profile->GetTopDownRoot();
806 const v8::CpuProfileNode* start_node = GetChild(env.local(), root, "start");
807 GetChild(env.local(), start_node, "get foo");
808 GetChild(env.local(), start_node, "set foo");
809
810 profile->Delete();
811 }
812
813
814 // Test that native accessors are properly reported in the CPU profile.
815 // This test makes sure that the accessors are called enough times to become
816 // hot and to trigger optimizations.
TEST(NativeAccessorMonomorphicIC)817 TEST(NativeAccessorMonomorphicIC) {
818 LocalContext env;
819 v8::Isolate* isolate = env->GetIsolate();
820 v8::HandleScope scope(isolate);
821
822 v8::Local<v8::FunctionTemplate> func_template =
823 v8::FunctionTemplate::New(isolate);
824 v8::Local<v8::ObjectTemplate> instance_template =
825 func_template->InstanceTemplate();
826
827 TestApiCallbacks accessors(1);
828 v8::Local<v8::External> data =
829 v8::External::New(isolate, &accessors);
830 instance_template->SetAccessor(v8_str("foo"), &TestApiCallbacks::Getter,
831 &TestApiCallbacks::Setter, data);
832 v8::Local<v8::Function> func =
833 func_template->GetFunction(env.local()).ToLocalChecked();
834 v8::Local<v8::Object> instance =
835 func->NewInstance(env.local()).ToLocalChecked();
836 env->Global()->Set(env.local(), v8_str("instance"), instance).FromJust();
837
838 CompileRun(native_accessor_test_source);
839 v8::Local<v8::Function> function = GetFunction(env.local(), "start");
840
841 {
842 // Make sure accessors ICs are in monomorphic state before starting
843 // profiling.
844 accessors.set_warming_up(true);
845 int32_t warm_up_iterations = 3;
846 v8::Local<v8::Value> args[] = {
847 v8::Integer::New(isolate, warm_up_iterations)};
848 function->Call(env.local(), env->Global(), arraysize(args), args)
849 .ToLocalChecked();
850 accessors.set_warming_up(false);
851 }
852
853 int32_t repeat_count = 100;
854 v8::Local<v8::Value> args[] = {v8::Integer::New(isolate, repeat_count)};
855 v8::CpuProfile* profile =
856 RunProfiler(env.local(), function, args, arraysize(args), 0, 100);
857
858 const v8::CpuProfileNode* root = profile->GetTopDownRoot();
859 const v8::CpuProfileNode* start_node = GetChild(env.local(), root, "start");
860 GetChild(env.local(), start_node, "get foo");
861 GetChild(env.local(), start_node, "set foo");
862
863 profile->Delete();
864 }
865
866
867 static const char* native_method_test_source = "function start(count) {\n"
868 " for (var i = 0; i < count; i++) {\n"
869 " instance.fooMethod();\n"
870 " }\n"
871 "}\n";
872
873
TEST(NativeMethodUninitializedIC)874 TEST(NativeMethodUninitializedIC) {
875 LocalContext env;
876 v8::Isolate* isolate = env->GetIsolate();
877 v8::HandleScope scope(isolate);
878
879 TestApiCallbacks callbacks(100);
880 v8::Local<v8::External> data =
881 v8::External::New(isolate, &callbacks);
882
883 v8::Local<v8::FunctionTemplate> func_template =
884 v8::FunctionTemplate::New(isolate);
885 func_template->SetClassName(v8_str("Test_InstanceCostructor"));
886 v8::Local<v8::ObjectTemplate> proto_template =
887 func_template->PrototypeTemplate();
888 v8::Local<v8::Signature> signature =
889 v8::Signature::New(isolate, func_template);
890 proto_template->Set(
891 v8_str("fooMethod"),
892 v8::FunctionTemplate::New(isolate, &TestApiCallbacks::Callback, data,
893 signature, 0));
894
895 v8::Local<v8::Function> func =
896 func_template->GetFunction(env.local()).ToLocalChecked();
897 v8::Local<v8::Object> instance =
898 func->NewInstance(env.local()).ToLocalChecked();
899 env->Global()->Set(env.local(), v8_str("instance"), instance).FromJust();
900
901 CompileRun(native_method_test_source);
902 v8::Local<v8::Function> function = GetFunction(env.local(), "start");
903
904 int32_t repeat_count = 1;
905 v8::Local<v8::Value> args[] = {v8::Integer::New(isolate, repeat_count)};
906 v8::CpuProfile* profile =
907 RunProfiler(env.local(), function, args, arraysize(args), 0, 100);
908
909 const v8::CpuProfileNode* root = profile->GetTopDownRoot();
910 const v8::CpuProfileNode* start_node = GetChild(env.local(), root, "start");
911 GetChild(env.local(), start_node, "fooMethod");
912
913 profile->Delete();
914 }
915
916
TEST(NativeMethodMonomorphicIC)917 TEST(NativeMethodMonomorphicIC) {
918 LocalContext env;
919 v8::Isolate* isolate = env->GetIsolate();
920 v8::HandleScope scope(isolate);
921
922 TestApiCallbacks callbacks(1);
923 v8::Local<v8::External> data =
924 v8::External::New(isolate, &callbacks);
925
926 v8::Local<v8::FunctionTemplate> func_template =
927 v8::FunctionTemplate::New(isolate);
928 func_template->SetClassName(v8_str("Test_InstanceCostructor"));
929 v8::Local<v8::ObjectTemplate> proto_template =
930 func_template->PrototypeTemplate();
931 v8::Local<v8::Signature> signature =
932 v8::Signature::New(isolate, func_template);
933 proto_template->Set(
934 v8_str("fooMethod"),
935 v8::FunctionTemplate::New(isolate, &TestApiCallbacks::Callback, data,
936 signature, 0));
937
938 v8::Local<v8::Function> func =
939 func_template->GetFunction(env.local()).ToLocalChecked();
940 v8::Local<v8::Object> instance =
941 func->NewInstance(env.local()).ToLocalChecked();
942 env->Global()->Set(env.local(), v8_str("instance"), instance).FromJust();
943
944 CompileRun(native_method_test_source);
945 v8::Local<v8::Function> function = GetFunction(env.local(), "start");
946 {
947 // Make sure method ICs are in monomorphic state before starting
948 // profiling.
949 callbacks.set_warming_up(true);
950 int32_t warm_up_iterations = 3;
951 v8::Local<v8::Value> args[] = {
952 v8::Integer::New(isolate, warm_up_iterations)};
953 function->Call(env.local(), env->Global(), arraysize(args), args)
954 .ToLocalChecked();
955 callbacks.set_warming_up(false);
956 }
957
958 int32_t repeat_count = 100;
959 v8::Local<v8::Value> args[] = {v8::Integer::New(isolate, repeat_count)};
960 v8::CpuProfile* profile =
961 RunProfiler(env.local(), function, args, arraysize(args), 0, 200);
962
963 const v8::CpuProfileNode* root = profile->GetTopDownRoot();
964 GetChild(env.local(), root, "start");
965 const v8::CpuProfileNode* start_node = GetChild(env.local(), root, "start");
966 GetChild(env.local(), start_node, "fooMethod");
967
968 profile->Delete();
969 }
970
971
972 static const char* bound_function_test_source =
973 "function foo() {\n"
974 " startProfiling('my_profile');\n"
975 "}\n"
976 "function start() {\n"
977 " var callback = foo.bind(this);\n"
978 " callback();\n"
979 "}";
980
981
TEST(BoundFunctionCall)982 TEST(BoundFunctionCall) {
983 v8::HandleScope scope(CcTest::isolate());
984 v8::Local<v8::Context> env = CcTest::NewContext(PROFILER_EXTENSION);
985 v8::Context::Scope context_scope(env);
986
987 CompileRun(bound_function_test_source);
988 v8::Local<v8::Function> function = GetFunction(env, "start");
989
990 v8::CpuProfile* profile = RunProfiler(env, function, NULL, 0);
991
992 const v8::CpuProfileNode* root = profile->GetTopDownRoot();
993
994 const v8::CpuProfileNode* start_node = GetChild(env, root, "start");
995 GetChild(env, start_node, "foo");
996
997 profile->Delete();
998 }
999
1000 // This tests checks distribution of the samples through the source lines.
TickLines(bool optimize)1001 static void TickLines(bool optimize) {
1002 CcTest::InitializeVM();
1003 LocalContext env;
1004 i::FLAG_allow_natives_syntax = true;
1005 i::FLAG_turbo_source_positions = true;
1006 i::Isolate* isolate = CcTest::i_isolate();
1007 i::Factory* factory = isolate->factory();
1008 i::HandleScope scope(isolate);
1009
1010 i::EmbeddedVector<char, 512> script;
1011
1012 const char* func_name = "func";
1013 const char* opt_func =
1014 optimize ? "%OptimizeFunctionOnNextCall" : "%NeverOptimizeFunction";
1015 i::SNPrintF(script,
1016 "function %s() {\n"
1017 " var n = 0;\n"
1018 " var m = 100*100;\n"
1019 " while (m > 1) {\n"
1020 " m--;\n"
1021 " n += m * m * m;\n"
1022 " }\n"
1023 "}\n"
1024 "%s(%s);\n"
1025 "%s();\n",
1026 func_name, opt_func, func_name, func_name);
1027
1028 CompileRun(script.start());
1029
1030 i::Handle<i::JSFunction> func = i::Handle<i::JSFunction>::cast(
1031 v8::Utils::OpenHandle(*GetFunction(env.local(), func_name)));
1032 CHECK(func->shared());
1033 CHECK(func->shared()->abstract_code());
1034 i::AbstractCode* code = func->abstract_code();
1035 CHECK(code);
1036 i::Address code_address = code->instruction_start();
1037 CHECK(code_address);
1038
1039 CpuProfilesCollection* profiles = new CpuProfilesCollection(isolate);
1040 ProfileGenerator* generator = new ProfileGenerator(profiles);
1041 ProfilerEventsProcessor* processor = new ProfilerEventsProcessor(
1042 generator, nullptr, v8::base::TimeDelta::FromMicroseconds(100));
1043 CpuProfiler profiler(isolate, profiles, generator, processor);
1044 profiles->StartProfiling("", false);
1045 processor->Start();
1046 ProfilerListener profiler_listener(isolate);
1047 isolate->code_event_dispatcher()->AddListener(&profiler_listener);
1048 profiler_listener.AddObserver(&profiler);
1049
1050 // Enqueue code creation events.
1051 i::Handle<i::String> str = factory->NewStringFromAsciiChecked(func_name);
1052 int line = 1;
1053 int column = 1;
1054 profiler_listener.CodeCreateEvent(i::Logger::FUNCTION_TAG, code,
1055 func->shared(), *str, line, column);
1056
1057 // Enqueue a tick event to enable code events processing.
1058 EnqueueTickSampleEvent(processor, code_address);
1059
1060 profiler_listener.RemoveObserver(&profiler);
1061 isolate->code_event_dispatcher()->RemoveListener(&profiler_listener);
1062 processor->StopSynchronously();
1063
1064 CpuProfile* profile = profiles->StopProfiling("");
1065 CHECK(profile);
1066
1067 // Check the state of profile generator.
1068 CodeEntry* func_entry = generator->code_map()->FindEntry(code_address);
1069 CHECK(func_entry);
1070 CHECK_EQ(0, strcmp(func_name, func_entry->name()));
1071 const i::JITLineInfoTable* line_info = func_entry->line_info();
1072 CHECK(line_info);
1073 CHECK(!line_info->empty());
1074
1075 // Check the hit source lines using V8 Public APIs.
1076 const i::ProfileTree* tree = profile->top_down();
1077 ProfileNode* root = tree->root();
1078 CHECK(root);
1079 ProfileNode* func_node = root->FindChild(func_entry);
1080 CHECK(func_node);
1081
1082 // Add 10 faked ticks to source line #5.
1083 int hit_line = 5;
1084 int hit_count = 10;
1085 for (int i = 0; i < hit_count; i++) func_node->IncrementLineTicks(hit_line);
1086
1087 unsigned int line_count = func_node->GetHitLineCount();
1088 CHECK_EQ(2u, line_count); // Expect two hit source lines - #1 and #5.
1089 ScopedVector<v8::CpuProfileNode::LineTick> entries(line_count);
1090 CHECK(func_node->GetLineTicks(&entries[0], line_count));
1091 int value = 0;
1092 for (int i = 0; i < entries.length(); i++)
1093 if (entries[i].line == hit_line) {
1094 value = entries[i].hit_count;
1095 break;
1096 }
1097 CHECK_EQ(hit_count, value);
1098 }
1099
TEST(TickLinesBaseline)1100 TEST(TickLinesBaseline) { TickLines(false); }
1101
TEST(TickLinesOptimized)1102 TEST(TickLinesOptimized) { TickLines(true); }
1103
1104 static const char* call_function_test_source =
1105 "%NeverOptimizeFunction(bar);\n"
1106 "%NeverOptimizeFunction(start);\n"
1107 "function bar(n) {\n"
1108 " var s = 0;\n"
1109 " for (var i = 0; i < n; i++) s += i * i * i;\n"
1110 " return s;\n"
1111 "}\n"
1112 "function start(duration) {\n"
1113 " var start = Date.now();\n"
1114 " do {\n"
1115 " for (var i = 0; i < 100; ++i)\n"
1116 " bar.call(this, 1000);\n"
1117 " } while (Date.now() - start < duration);\n"
1118 "}";
1119
1120 // Test that if we sampled thread when it was inside FunctionCall buitin then
1121 // its caller frame will be '(unresolved function)' as we have no reliable way
1122 // to resolve it.
1123 //
1124 // [Top down]:
1125 // 96 0 (root) [-1] #1
1126 // 1 1 (garbage collector) [-1] #4
1127 // 5 0 (unresolved function) [-1] #5
1128 // 5 5 call [-1] #6
1129 // 71 70 start [-1] #3
1130 // 1 1 bar [-1] #7
1131 // 19 19 (program) [-1] #2
TEST(FunctionCallSample)1132 TEST(FunctionCallSample) {
1133 i::FLAG_allow_natives_syntax = true;
1134 LocalContext env;
1135 v8::HandleScope scope(env->GetIsolate());
1136
1137 // Collect garbage that might have be generated while installing
1138 // extensions.
1139 CcTest::heap()->CollectAllGarbage();
1140
1141 CompileRun(call_function_test_source);
1142 v8::Local<v8::Function> function = GetFunction(env.local(), "start");
1143
1144 int32_t duration_ms = 100;
1145 v8::Local<v8::Value> args[] = {
1146 v8::Integer::New(env->GetIsolate(), duration_ms)};
1147 v8::CpuProfile* profile =
1148 RunProfiler(env.local(), function, args, arraysize(args), 1000);
1149
1150 const v8::CpuProfileNode* root = profile->GetTopDownRoot();
1151 const v8::CpuProfileNode* start_node = GetChild(env.local(), root, "start");
1152 GetChild(env.local(), start_node, "bar");
1153
1154 const v8::CpuProfileNode* unresolved_node =
1155 FindChild(env.local(), root, i::CodeEntry::kUnresolvedFunctionName);
1156 CHECK(!unresolved_node || GetChild(env.local(), unresolved_node, "call"));
1157
1158 profile->Delete();
1159 }
1160
1161 static const char* function_apply_test_source =
1162 "%NeverOptimizeFunction(bar);\n"
1163 "%NeverOptimizeFunction(test);\n"
1164 "%NeverOptimizeFunction(start);\n"
1165 "function bar(n) {\n"
1166 " var s = 0;\n"
1167 " for (var i = 0; i < n; i++) s += i * i * i;\n"
1168 " return s;\n"
1169 "}\n"
1170 "function test() {\n"
1171 " bar.apply(this, [1000]);\n"
1172 "}\n"
1173 "function start(duration) {\n"
1174 " var start = Date.now();\n"
1175 " do {\n"
1176 " for (var i = 0; i < 100; ++i) test();\n"
1177 " } while (Date.now() - start < duration);\n"
1178 "}";
1179
1180 // [Top down]:
1181 // 94 0 (root) [-1] #0 1
1182 // 2 2 (garbage collector) [-1] #0 7
1183 // 82 49 start [-1] #16 3
1184 // 1 0 (unresolved function) [-1] #0 8
1185 // 1 1 apply [-1] #0 9
1186 // 32 21 test [-1] #16 4
1187 // 2 2 bar [-1] #16 6
1188 // 10 10 (program) [-1] #0 2
TEST(FunctionApplySample)1189 TEST(FunctionApplySample) {
1190 i::FLAG_allow_natives_syntax = true;
1191 LocalContext env;
1192 v8::HandleScope scope(env->GetIsolate());
1193
1194 CompileRun(function_apply_test_source);
1195 v8::Local<v8::Function> function = GetFunction(env.local(), "start");
1196
1197 int32_t duration_ms = 100;
1198 v8::Local<v8::Value> args[] = {
1199 v8::Integer::New(env->GetIsolate(), duration_ms)};
1200
1201 v8::CpuProfile* profile =
1202 RunProfiler(env.local(), function, args, arraysize(args), 1000);
1203
1204 const v8::CpuProfileNode* root = profile->GetTopDownRoot();
1205 const v8::CpuProfileNode* start_node = GetChild(env.local(), root, "start");
1206 const v8::CpuProfileNode* test_node =
1207 GetChild(env.local(), start_node, "test");
1208 GetChild(env.local(), test_node, "bar");
1209
1210 const v8::CpuProfileNode* unresolved_node =
1211 FindChild(env.local(), start_node, CodeEntry::kUnresolvedFunctionName);
1212 CHECK(!unresolved_node || GetChild(env.local(), unresolved_node, "apply"));
1213
1214 profile->Delete();
1215 }
1216
1217 static const char* cpu_profiler_deep_stack_test_source =
1218 "function foo(n) {\n"
1219 " if (n)\n"
1220 " foo(n - 1);\n"
1221 " else\n"
1222 " collectSample();\n"
1223 "}\n"
1224 "function start() {\n"
1225 " startProfiling('my_profile');\n"
1226 " foo(250);\n"
1227 "}\n";
1228
1229 // Check a deep stack
1230 //
1231 // [Top down]:
1232 // 0 (root) 0 #1
1233 // 2 (program) 0 #2
1234 // 0 start 21 #3 no reason
1235 // 0 foo 21 #4 no reason
1236 // 0 foo 21 #5 no reason
1237 // ....
1238 // 0 foo 21 #254 no reason
TEST(CpuProfileDeepStack)1239 TEST(CpuProfileDeepStack) {
1240 v8::HandleScope scope(CcTest::isolate());
1241 v8::Local<v8::Context> env = CcTest::NewContext(PROFILER_EXTENSION);
1242 v8::Context::Scope context_scope(env);
1243
1244 CompileRun(cpu_profiler_deep_stack_test_source);
1245 v8::Local<v8::Function> function = GetFunction(env, "start");
1246
1247 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler();
1248 v8::Local<v8::String> profile_name = v8_str("my_profile");
1249 function->Call(env, env->Global(), 0, NULL).ToLocalChecked();
1250 v8::CpuProfile* profile = cpu_profiler->StopProfiling(profile_name);
1251 CHECK(profile);
1252 // Dump collected profile to have a better diagnostic in case of failure.
1253 reinterpret_cast<i::CpuProfile*>(profile)->Print();
1254
1255 const v8::CpuProfileNode* root = profile->GetTopDownRoot();
1256 const v8::CpuProfileNode* node = GetChild(env, root, "start");
1257 for (int i = 0; i <= 250; ++i) {
1258 node = GetChild(env, node, "foo");
1259 }
1260 CHECK(!FindChild(env, node, "foo"));
1261
1262 profile->Delete();
1263 }
1264
1265 static const char* js_native_js_test_source =
1266 "%NeverOptimizeFunction(foo);\n"
1267 "%NeverOptimizeFunction(bar);\n"
1268 "%NeverOptimizeFunction(start);\n"
1269 "function foo(n) {\n"
1270 " var s = 0;\n"
1271 " for (var i = 0; i < n; i++) s += i * i * i;\n"
1272 " return s;\n"
1273 "}\n"
1274 "function bar() {\n"
1275 " foo(1000);\n"
1276 "}\n"
1277 "function start() {\n"
1278 " CallJsFunction(bar);\n"
1279 "}";
1280
CallJsFunction(const v8::FunctionCallbackInfo<v8::Value> & info)1281 static void CallJsFunction(const v8::FunctionCallbackInfo<v8::Value>& info) {
1282 v8::Local<v8::Function> function = info[0].As<v8::Function>();
1283 v8::Local<v8::Value> argv[] = {info[1]};
1284 function->Call(info.GetIsolate()->GetCurrentContext(), info.This(),
1285 arraysize(argv), argv)
1286 .ToLocalChecked();
1287 }
1288
1289 // [Top down]:
1290 // 58 0 (root) #0 1
1291 // 2 2 (program) #0 2
1292 // 56 1 start #16 3
1293 // 55 0 CallJsFunction #0 4
1294 // 55 1 bar #16 5
1295 // 54 54 foo #16 6
TEST(JsNativeJsSample)1296 TEST(JsNativeJsSample) {
1297 i::FLAG_allow_natives_syntax = true;
1298 v8::HandleScope scope(CcTest::isolate());
1299 v8::Local<v8::Context> env = CcTest::NewContext(PROFILER_EXTENSION);
1300 v8::Context::Scope context_scope(env);
1301
1302 v8::Local<v8::FunctionTemplate> func_template = v8::FunctionTemplate::New(
1303 env->GetIsolate(), CallJsFunction);
1304 v8::Local<v8::Function> func =
1305 func_template->GetFunction(env).ToLocalChecked();
1306 func->SetName(v8_str("CallJsFunction"));
1307 env->Global()->Set(env, v8_str("CallJsFunction"), func).FromJust();
1308
1309 CompileRun(js_native_js_test_source);
1310 v8::Local<v8::Function> function = GetFunction(env, "start");
1311
1312 v8::CpuProfile* profile = RunProfiler(env, function, NULL, 0, 1000);
1313
1314 const v8::CpuProfileNode* root = profile->GetTopDownRoot();
1315 const v8::CpuProfileNode* start_node = GetChild(env, root, "start");
1316 const v8::CpuProfileNode* native_node =
1317 GetChild(env, start_node, "CallJsFunction");
1318 const v8::CpuProfileNode* bar_node = GetChild(env, native_node, "bar");
1319 GetChild(env, bar_node, "foo");
1320
1321 profile->Delete();
1322 }
1323
1324 static const char* js_native_js_runtime_js_test_source =
1325 "%NeverOptimizeFunction(foo);\n"
1326 "%NeverOptimizeFunction(bar);\n"
1327 "%NeverOptimizeFunction(start);\n"
1328 "function foo(n) {\n"
1329 " var s = 0;\n"
1330 " for (var i = 0; i < n; i++) s += i * i * i;\n"
1331 " return s;\n"
1332 "}\n"
1333 "var bound = foo.bind(this);\n"
1334 "function bar() {\n"
1335 " bound(1000);\n"
1336 "}\n"
1337 "function start() {\n"
1338 " CallJsFunction(bar);\n"
1339 "}";
1340
1341 // [Top down]:
1342 // 57 0 (root) #0 1
1343 // 55 1 start #16 3
1344 // 54 0 CallJsFunction #0 4
1345 // 54 3 bar #16 5
1346 // 51 51 foo #16 6
1347 // 2 2 (program) #0 2
TEST(JsNativeJsRuntimeJsSample)1348 TEST(JsNativeJsRuntimeJsSample) {
1349 i::FLAG_allow_natives_syntax = true;
1350 v8::HandleScope scope(CcTest::isolate());
1351 v8::Local<v8::Context> env = CcTest::NewContext(PROFILER_EXTENSION);
1352 v8::Context::Scope context_scope(env);
1353
1354 v8::Local<v8::FunctionTemplate> func_template = v8::FunctionTemplate::New(
1355 env->GetIsolate(), CallJsFunction);
1356 v8::Local<v8::Function> func =
1357 func_template->GetFunction(env).ToLocalChecked();
1358 func->SetName(v8_str("CallJsFunction"));
1359 env->Global()->Set(env, v8_str("CallJsFunction"), func).FromJust();
1360
1361 CompileRun(js_native_js_runtime_js_test_source);
1362 v8::Local<v8::Function> function = GetFunction(env, "start");
1363 v8::CpuProfile* profile = RunProfiler(env, function, NULL, 0, 1000);
1364
1365 const v8::CpuProfileNode* root = profile->GetTopDownRoot();
1366 const v8::CpuProfileNode* start_node = GetChild(env, root, "start");
1367 const v8::CpuProfileNode* native_node =
1368 GetChild(env, start_node, "CallJsFunction");
1369 const v8::CpuProfileNode* bar_node = GetChild(env, native_node, "bar");
1370 GetChild(env, bar_node, "foo");
1371
1372 profile->Delete();
1373 }
1374
CallJsFunction2(const v8::FunctionCallbackInfo<v8::Value> & info)1375 static void CallJsFunction2(const v8::FunctionCallbackInfo<v8::Value>& info) {
1376 v8::base::OS::Print("In CallJsFunction2\n");
1377 CallJsFunction(info);
1378 }
1379
1380 static const char* js_native1_js_native2_js_test_source =
1381 "%NeverOptimizeFunction(foo);\n"
1382 "%NeverOptimizeFunction(bar);\n"
1383 "%NeverOptimizeFunction(start);\n"
1384 "function foo() {\n"
1385 " var s = 0;\n"
1386 " for (var i = 0; i < 1000; i++) s += i * i * i;\n"
1387 " return s;\n"
1388 "}\n"
1389 "function bar() {\n"
1390 " CallJsFunction2(foo);\n"
1391 "}\n"
1392 "function start() {\n"
1393 " CallJsFunction1(bar);\n"
1394 "}";
1395
1396 // [Top down]:
1397 // 57 0 (root) #0 1
1398 // 55 1 start #16 3
1399 // 54 0 CallJsFunction1 #0 4
1400 // 54 0 bar #16 5
1401 // 54 0 CallJsFunction2 #0 6
1402 // 54 54 foo #16 7
1403 // 2 2 (program) #0 2
TEST(JsNative1JsNative2JsSample)1404 TEST(JsNative1JsNative2JsSample) {
1405 i::FLAG_allow_natives_syntax = true;
1406 v8::HandleScope scope(CcTest::isolate());
1407 v8::Local<v8::Context> env = CcTest::NewContext(PROFILER_EXTENSION);
1408 v8::Context::Scope context_scope(env);
1409
1410 v8::Local<v8::Function> func1 =
1411 v8::FunctionTemplate::New(env->GetIsolate(), CallJsFunction)
1412 ->GetFunction(env)
1413 .ToLocalChecked();
1414 func1->SetName(v8_str("CallJsFunction1"));
1415 env->Global()->Set(env, v8_str("CallJsFunction1"), func1).FromJust();
1416
1417 v8::Local<v8::Function> func2 =
1418 v8::FunctionTemplate::New(env->GetIsolate(), CallJsFunction2)
1419 ->GetFunction(env)
1420 .ToLocalChecked();
1421 func2->SetName(v8_str("CallJsFunction2"));
1422 env->Global()->Set(env, v8_str("CallJsFunction2"), func2).FromJust();
1423
1424 CompileRun(js_native1_js_native2_js_test_source);
1425 v8::Local<v8::Function> function = GetFunction(env, "start");
1426
1427 v8::CpuProfile* profile = RunProfiler(env, function, NULL, 0, 1000);
1428
1429 const v8::CpuProfileNode* root = profile->GetTopDownRoot();
1430 const v8::CpuProfileNode* start_node = GetChild(env, root, "start");
1431 const v8::CpuProfileNode* native_node1 =
1432 GetChild(env, start_node, "CallJsFunction1");
1433 const v8::CpuProfileNode* bar_node = GetChild(env, native_node1, "bar");
1434 const v8::CpuProfileNode* native_node2 =
1435 GetChild(env, bar_node, "CallJsFunction2");
1436 GetChild(env, native_node2, "foo");
1437
1438 profile->Delete();
1439 }
1440
1441 static const char* js_force_collect_sample_source =
1442 "function start() {\n"
1443 " CallCollectSample();\n"
1444 "}";
1445
TEST(CollectSampleAPI)1446 TEST(CollectSampleAPI) {
1447 v8::HandleScope scope(CcTest::isolate());
1448 v8::Local<v8::Context> env = CcTest::NewContext(PROFILER_EXTENSION);
1449 v8::Context::Scope context_scope(env);
1450
1451 v8::Local<v8::FunctionTemplate> func_template =
1452 v8::FunctionTemplate::New(env->GetIsolate(), CallCollectSample);
1453 v8::Local<v8::Function> func =
1454 func_template->GetFunction(env).ToLocalChecked();
1455 func->SetName(v8_str("CallCollectSample"));
1456 env->Global()->Set(env, v8_str("CallCollectSample"), func).FromJust();
1457
1458 CompileRun(js_force_collect_sample_source);
1459 v8::Local<v8::Function> function = GetFunction(env, "start");
1460 v8::CpuProfile* profile = RunProfiler(env, function, NULL, 0, 0);
1461
1462 const v8::CpuProfileNode* root = profile->GetTopDownRoot();
1463 const v8::CpuProfileNode* start_node = GetChild(env, root, "start");
1464 CHECK_LE(1, start_node->GetChildrenCount());
1465 GetChild(env, start_node, "CallCollectSample");
1466
1467 profile->Delete();
1468 }
1469
1470 static const char* js_native_js_runtime_multiple_test_source =
1471 "%NeverOptimizeFunction(foo);\n"
1472 "%NeverOptimizeFunction(bar);\n"
1473 "%NeverOptimizeFunction(start);\n"
1474 "function foo() {\n"
1475 " return Math.sin(Math.random());\n"
1476 "}\n"
1477 "var bound = foo.bind(this);\n"
1478 "function bar() {\n"
1479 " return bound();\n"
1480 "}\n"
1481 "function start() {\n"
1482 " startProfiling('my_profile');\n"
1483 " var startTime = Date.now();\n"
1484 " do {\n"
1485 " CallJsFunction(bar);\n"
1486 " } while (Date.now() - startTime < 200);\n"
1487 "}";
1488
1489 // The test check multiple entrances/exits between JS and native code.
1490 //
1491 // [Top down]:
1492 // (root) #0 1
1493 // start #16 3
1494 // CallJsFunction #0 4
1495 // bar #16 5
1496 // foo #16 6
1497 // (program) #0 2
TEST(JsNativeJsRuntimeJsSampleMultiple)1498 TEST(JsNativeJsRuntimeJsSampleMultiple) {
1499 i::FLAG_allow_natives_syntax = true;
1500 v8::HandleScope scope(CcTest::isolate());
1501 v8::Local<v8::Context> env = CcTest::NewContext(PROFILER_EXTENSION);
1502 v8::Context::Scope context_scope(env);
1503
1504 v8::Local<v8::FunctionTemplate> func_template =
1505 v8::FunctionTemplate::New(env->GetIsolate(), CallJsFunction);
1506 v8::Local<v8::Function> func =
1507 func_template->GetFunction(env).ToLocalChecked();
1508 func->SetName(v8_str("CallJsFunction"));
1509 env->Global()->Set(env, v8_str("CallJsFunction"), func).FromJust();
1510
1511 CompileRun(js_native_js_runtime_multiple_test_source);
1512 v8::Local<v8::Function> function = GetFunction(env, "start");
1513
1514 v8::CpuProfile* profile = RunProfiler(env, function, NULL, 0, 500, 500);
1515
1516 const v8::CpuProfileNode* root = profile->GetTopDownRoot();
1517 const v8::CpuProfileNode* start_node = GetChild(env, root, "start");
1518 const v8::CpuProfileNode* native_node =
1519 GetChild(env, start_node, "CallJsFunction");
1520 const v8::CpuProfileNode* bar_node = GetChild(env, native_node, "bar");
1521 GetChild(env, bar_node, "foo");
1522
1523 profile->Delete();
1524 }
1525
1526 static const char* inlining_test_source =
1527 "%NeverOptimizeFunction(action);\n"
1528 "%NeverOptimizeFunction(start);\n"
1529 "%OptimizeFunctionOnNextCall(level1);\n"
1530 "%OptimizeFunctionOnNextCall(level2);\n"
1531 "%OptimizeFunctionOnNextCall(level3);\n"
1532 "var finish = false;\n"
1533 "function action(n) {\n"
1534 " var s = 0;\n"
1535 " for (var i = 0; i < n; ++i) s += i*i*i;\n"
1536 " if (finish)\n"
1537 " startProfiling('my_profile');\n"
1538 " return s;\n"
1539 "}\n"
1540 "function level3() { return action(100); }\n"
1541 "function level2() { return level3() * 2; }\n"
1542 "function level1() { return level2(); }\n"
1543 "function start() {\n"
1544 " var n = 100;\n"
1545 " while (--n)\n"
1546 " level1();\n"
1547 " finish = true;\n"
1548 " level1();\n"
1549 "}";
1550
1551 // The test check multiple entrances/exits between JS and native code.
1552 //
1553 // [Top down]:
1554 // (root) #0 1
1555 // start #16 3
1556 // level1 #0 4
1557 // level2 #16 5
1558 // level3 #16 6
1559 // action #16 7
1560 // (program) #0 2
TEST(Inlining)1561 TEST(Inlining) {
1562 i::FLAG_allow_natives_syntax = true;
1563 v8::HandleScope scope(CcTest::isolate());
1564 v8::Local<v8::Context> env = CcTest::NewContext(PROFILER_EXTENSION);
1565 v8::Context::Scope context_scope(env);
1566
1567 CompileRun(inlining_test_source);
1568 v8::Local<v8::Function> function = GetFunction(env, "start");
1569
1570 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler();
1571 v8::Local<v8::String> profile_name = v8_str("my_profile");
1572 function->Call(env, env->Global(), 0, NULL).ToLocalChecked();
1573 v8::CpuProfile* profile = cpu_profiler->StopProfiling(profile_name);
1574 CHECK(profile);
1575 // Dump collected profile to have a better diagnostic in case of failure.
1576 reinterpret_cast<i::CpuProfile*>(profile)->Print();
1577
1578 const v8::CpuProfileNode* root = profile->GetTopDownRoot();
1579 const v8::CpuProfileNode* start_node = GetChild(env, root, "start");
1580 const v8::CpuProfileNode* level1_node = GetChild(env, start_node, "level1");
1581 const v8::CpuProfileNode* level2_node = GetChild(env, level1_node, "level2");
1582 const v8::CpuProfileNode* level3_node = GetChild(env, level2_node, "level3");
1583 GetChild(env, level3_node, "action");
1584
1585 profile->Delete();
1586 }
1587
1588 // [Top down]:
1589 // 0 (root) #0 1
1590 // 2 (program) #0 2
1591 // 3 (idle) #0 3
TEST(IdleTime)1592 TEST(IdleTime) {
1593 LocalContext env;
1594 v8::HandleScope scope(env->GetIsolate());
1595 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler();
1596
1597 v8::Local<v8::String> profile_name = v8_str("my_profile");
1598 cpu_profiler->StartProfiling(profile_name);
1599
1600 i::Isolate* isolate = CcTest::i_isolate();
1601 i::ProfilerEventsProcessor* processor = isolate->cpu_profiler()->processor();
1602
1603 processor->AddCurrentStack(isolate, true);
1604 cpu_profiler->SetIdle(true);
1605 for (int i = 0; i < 3; i++) {
1606 processor->AddCurrentStack(isolate, true);
1607 }
1608 cpu_profiler->SetIdle(false);
1609 processor->AddCurrentStack(isolate, true);
1610
1611 v8::CpuProfile* profile = cpu_profiler->StopProfiling(profile_name);
1612 CHECK(profile);
1613 // Dump collected profile to have a better diagnostic in case of failure.
1614 reinterpret_cast<i::CpuProfile*>(profile)->Print();
1615
1616 const v8::CpuProfileNode* root = profile->GetTopDownRoot();
1617 const v8::CpuProfileNode* program_node =
1618 GetChild(env.local(), root, CodeEntry::kProgramEntryName);
1619 CHECK_EQ(0, program_node->GetChildrenCount());
1620 CHECK_GE(program_node->GetHitCount(), 2u);
1621
1622 const v8::CpuProfileNode* idle_node =
1623 GetChild(env.local(), root, CodeEntry::kIdleEntryName);
1624 CHECK_EQ(0, idle_node->GetChildrenCount());
1625 CHECK_GE(idle_node->GetHitCount(), 3u);
1626
1627 profile->Delete();
1628 }
1629
CheckFunctionDetails(v8::Isolate * isolate,const v8::CpuProfileNode * node,const char * name,const char * script_name,int script_id,int line,int column)1630 static void CheckFunctionDetails(v8::Isolate* isolate,
1631 const v8::CpuProfileNode* node,
1632 const char* name, const char* script_name,
1633 int script_id, int line, int column) {
1634 v8::Local<v8::Context> context = isolate->GetCurrentContext();
1635 CHECK(v8_str(name)->Equals(context, node->GetFunctionName()).FromJust());
1636 CHECK(v8_str(script_name)
1637 ->Equals(context, node->GetScriptResourceName())
1638 .FromJust());
1639 CHECK_EQ(script_id, node->GetScriptId());
1640 CHECK_EQ(line, node->GetLineNumber());
1641 CHECK_EQ(column, node->GetColumnNumber());
1642 }
1643
1644
TEST(FunctionDetails)1645 TEST(FunctionDetails) {
1646 i::FLAG_allow_natives_syntax = true;
1647 v8::HandleScope scope(CcTest::isolate());
1648 v8::Local<v8::Context> env = CcTest::NewContext(PROFILER_EXTENSION);
1649 v8::Context::Scope context_scope(env);
1650
1651 v8::Local<v8::Script> script_a = CompileWithOrigin(
1652 "%NeverOptimizeFunction(foo);\n"
1653 "%NeverOptimizeFunction(bar);\n"
1654 " function foo\n() { bar(); }\n"
1655 " function bar() { startProfiling(); }\n",
1656 "script_a");
1657 script_a->Run(env).ToLocalChecked();
1658 v8::Local<v8::Script> script_b = CompileWithOrigin(
1659 "%NeverOptimizeFunction(baz);"
1660 "\n\n function baz() { foo(); }\n"
1661 "\n\nbaz();\n"
1662 "stopProfiling();\n",
1663 "script_b");
1664 script_b->Run(env).ToLocalChecked();
1665 const v8::CpuProfile* profile = i::ProfilerExtension::last_profile;
1666 const v8::CpuProfileNode* current = profile->GetTopDownRoot();
1667 reinterpret_cast<ProfileNode*>(
1668 const_cast<v8::CpuProfileNode*>(current))->Print(0);
1669 // The tree should look like this:
1670 // 0 (root) 0 #1
1671 // 0 "" 19 #2 no reason script_b:1
1672 // 0 baz 19 #3 TryCatchStatement script_b:3
1673 // 0 foo 18 #4 TryCatchStatement script_a:2
1674 // 1 bar 18 #5 no reason script_a:3
1675 const v8::CpuProfileNode* root = profile->GetTopDownRoot();
1676 const v8::CpuProfileNode* script = GetChild(env, root, "");
1677 CheckFunctionDetails(env->GetIsolate(), script, "", "script_b",
1678 script_b->GetUnboundScript()->GetId(), 1, 1);
1679 const v8::CpuProfileNode* baz = GetChild(env, script, "baz");
1680 CheckFunctionDetails(env->GetIsolate(), baz, "baz", "script_b",
1681 script_b->GetUnboundScript()->GetId(), 3, 16);
1682 const v8::CpuProfileNode* foo = GetChild(env, baz, "foo");
1683 CheckFunctionDetails(env->GetIsolate(), foo, "foo", "script_a",
1684 script_a->GetUnboundScript()->GetId(), 4, 1);
1685 const v8::CpuProfileNode* bar = GetChild(env, foo, "bar");
1686 CheckFunctionDetails(env->GetIsolate(), bar, "bar", "script_a",
1687 script_a->GetUnboundScript()->GetId(), 5, 14);
1688 }
1689
1690
TEST(DontStopOnFinishedProfileDelete)1691 TEST(DontStopOnFinishedProfileDelete) {
1692 v8::HandleScope scope(CcTest::isolate());
1693 v8::Local<v8::Context> env = CcTest::NewContext(PROFILER_EXTENSION);
1694 v8::Context::Scope context_scope(env);
1695
1696 v8::CpuProfiler* profiler = env->GetIsolate()->GetCpuProfiler();
1697 i::CpuProfiler* iprofiler = reinterpret_cast<i::CpuProfiler*>(profiler);
1698
1699 CHECK_EQ(0, iprofiler->GetProfilesCount());
1700 v8::Local<v8::String> outer = v8_str("outer");
1701 profiler->StartProfiling(outer);
1702 CHECK_EQ(0, iprofiler->GetProfilesCount());
1703
1704 v8::Local<v8::String> inner = v8_str("inner");
1705 profiler->StartProfiling(inner);
1706 CHECK_EQ(0, iprofiler->GetProfilesCount());
1707
1708 v8::CpuProfile* inner_profile = profiler->StopProfiling(inner);
1709 CHECK(inner_profile);
1710 CHECK_EQ(1, iprofiler->GetProfilesCount());
1711 inner_profile->Delete();
1712 inner_profile = NULL;
1713 CHECK_EQ(0, iprofiler->GetProfilesCount());
1714
1715 v8::CpuProfile* outer_profile = profiler->StopProfiling(outer);
1716 CHECK(outer_profile);
1717 CHECK_EQ(1, iprofiler->GetProfilesCount());
1718 outer_profile->Delete();
1719 outer_profile = NULL;
1720 CHECK_EQ(0, iprofiler->GetProfilesCount());
1721 }
1722
1723
GetBranchDeoptReason(v8::Local<v8::Context> context,i::CpuProfile * iprofile,const char * branch[],int length)1724 const char* GetBranchDeoptReason(v8::Local<v8::Context> context,
1725 i::CpuProfile* iprofile, const char* branch[],
1726 int length) {
1727 v8::CpuProfile* profile = reinterpret_cast<v8::CpuProfile*>(iprofile);
1728 const ProfileNode* iopt_function = NULL;
1729 iopt_function = GetSimpleBranch(context, profile, branch, length);
1730 CHECK_EQ(1U, iopt_function->deopt_infos().size());
1731 return iopt_function->deopt_infos()[0].deopt_reason;
1732 }
1733
1734
1735 // deopt at top function
TEST(CollectDeoptEvents)1736 TEST(CollectDeoptEvents) {
1737 if (!CcTest::i_isolate()->use_crankshaft() || i::FLAG_always_opt) return;
1738 i::FLAG_allow_natives_syntax = true;
1739 v8::HandleScope scope(CcTest::isolate());
1740 v8::Local<v8::Context> env = CcTest::NewContext(PROFILER_EXTENSION);
1741 v8::Context::Scope context_scope(env);
1742 v8::Isolate* isolate = env->GetIsolate();
1743 v8::CpuProfiler* profiler = isolate->GetCpuProfiler();
1744 i::CpuProfiler* iprofiler = reinterpret_cast<i::CpuProfiler*>(profiler);
1745
1746 const char opt_source[] =
1747 "function opt_function%d(value, depth) {\n"
1748 " if (depth) return opt_function%d(value, depth - 1);\n"
1749 "\n"
1750 " return 10 / value;\n"
1751 "}\n"
1752 "\n";
1753
1754 for (int i = 0; i < 3; ++i) {
1755 i::EmbeddedVector<char, sizeof(opt_source) + 100> buffer;
1756 i::SNPrintF(buffer, opt_source, i, i);
1757 v8::Script::Compile(env, v8_str(buffer.start()))
1758 .ToLocalChecked()
1759 ->Run(env)
1760 .ToLocalChecked();
1761 }
1762
1763 const char* source =
1764 "startProfiling();\n"
1765 "\n"
1766 "opt_function0(1, 1);\n"
1767 "\n"
1768 "%OptimizeFunctionOnNextCall(opt_function0)\n"
1769 "\n"
1770 "opt_function0(1, 1);\n"
1771 "\n"
1772 "opt_function0(undefined, 1);\n"
1773 "\n"
1774 "opt_function1(1, 1);\n"
1775 "\n"
1776 "%OptimizeFunctionOnNextCall(opt_function1)\n"
1777 "\n"
1778 "opt_function1(1, 1);\n"
1779 "\n"
1780 "opt_function1(NaN, 1);\n"
1781 "\n"
1782 "opt_function2(1, 1);\n"
1783 "\n"
1784 "%OptimizeFunctionOnNextCall(opt_function2)\n"
1785 "\n"
1786 "opt_function2(1, 1);\n"
1787 "\n"
1788 "opt_function2(0, 1);\n"
1789 "\n"
1790 "stopProfiling();\n"
1791 "\n";
1792
1793 v8::Script::Compile(env, v8_str(source))
1794 .ToLocalChecked()
1795 ->Run(env)
1796 .ToLocalChecked();
1797 i::CpuProfile* iprofile = iprofiler->GetProfile(0);
1798 iprofile->Print();
1799 /* The expected profile
1800 [Top down]:
1801 0 (root) 0 #1
1802 23 32 #2
1803 1 opt_function2 31 #7
1804 1 opt_function2 31 #8
1805 ;;; deopted at script_id: 31 position: 106 with reason
1806 'division by zero'.
1807 2 opt_function0 29 #3
1808 4 opt_function0 29 #4
1809 ;;; deopted at script_id: 29 position: 108 with reason 'not a
1810 heap number'.
1811 0 opt_function1 30 #5
1812 1 opt_function1 30 #6
1813 ;;; deopted at script_id: 30 position: 108 with reason 'lost
1814 precision or NaN'.
1815 */
1816
1817 {
1818 const char* branch[] = {"", "opt_function0", "opt_function0"};
1819 CHECK_EQ(reason(i::Deoptimizer::kNotAHeapNumber),
1820 GetBranchDeoptReason(env, iprofile, branch, arraysize(branch)));
1821 }
1822 {
1823 const char* branch[] = {"", "opt_function1", "opt_function1"};
1824 const char* deopt_reason =
1825 GetBranchDeoptReason(env, iprofile, branch, arraysize(branch));
1826 if (deopt_reason != reason(i::Deoptimizer::kNaN) &&
1827 deopt_reason != reason(i::Deoptimizer::kLostPrecisionOrNaN)) {
1828 FATAL(deopt_reason);
1829 }
1830 }
1831 {
1832 const char* branch[] = {"", "opt_function2", "opt_function2"};
1833 CHECK_EQ(reason(i::Deoptimizer::kDivisionByZero),
1834 GetBranchDeoptReason(env, iprofile, branch, arraysize(branch)));
1835 }
1836 iprofiler->DeleteProfile(iprofile);
1837 }
1838
1839
TEST(SourceLocation)1840 TEST(SourceLocation) {
1841 i::FLAG_always_opt = true;
1842 i::FLAG_hydrogen_track_positions = true;
1843 LocalContext env;
1844 v8::HandleScope scope(CcTest::isolate());
1845
1846 const char* source =
1847 "function CompareStatementWithThis() {\n"
1848 " if (this === 1) {}\n"
1849 "}\n"
1850 "CompareStatementWithThis();\n";
1851
1852 v8::Script::Compile(env.local(), v8_str(source))
1853 .ToLocalChecked()
1854 ->Run(env.local())
1855 .ToLocalChecked();
1856 }
1857
1858
1859 static const char* inlined_source =
1860 "function opt_function(left, right) { var k = left / 10; var r = 10 / "
1861 "right; return k + r; }\n";
1862 // 0.........1.........2.........3.........4....*....5.........6......*..7
1863
1864
1865 // deopt at the first level inlined function
TEST(DeoptAtFirstLevelInlinedSource)1866 TEST(DeoptAtFirstLevelInlinedSource) {
1867 if (!CcTest::i_isolate()->use_crankshaft() || i::FLAG_always_opt) return;
1868 i::FLAG_allow_natives_syntax = true;
1869 v8::HandleScope scope(CcTest::isolate());
1870 v8::Local<v8::Context> env = CcTest::NewContext(PROFILER_EXTENSION);
1871 v8::Context::Scope context_scope(env);
1872 v8::Isolate* isolate = env->GetIsolate();
1873 v8::CpuProfiler* profiler = isolate->GetCpuProfiler();
1874 i::CpuProfiler* iprofiler = reinterpret_cast<i::CpuProfiler*>(profiler);
1875
1876 // 0.........1.........2.........3.........4.........5.........6.........7
1877 const char* source =
1878 "function test(left, right) { return opt_function(left, right); }\n"
1879 "\n"
1880 "startProfiling();\n"
1881 "\n"
1882 "test(10, 10);\n"
1883 "\n"
1884 "%OptimizeFunctionOnNextCall(test)\n"
1885 "\n"
1886 "test(10, 10);\n"
1887 "\n"
1888 "test(undefined, 10);\n"
1889 "\n"
1890 "stopProfiling();\n"
1891 "\n";
1892
1893 v8::Local<v8::Script> inlined_script = v8_compile(inlined_source);
1894 inlined_script->Run(env).ToLocalChecked();
1895 int inlined_script_id = inlined_script->GetUnboundScript()->GetId();
1896
1897 v8::Local<v8::Script> script = v8_compile(source);
1898 script->Run(env).ToLocalChecked();
1899 int script_id = script->GetUnboundScript()->GetId();
1900
1901 i::CpuProfile* iprofile = iprofiler->GetProfile(0);
1902 iprofile->Print();
1903 /* The expected profile output
1904 [Top down]:
1905 0 (root) 0 #1
1906 10 30 #2
1907 1 test 30 #3
1908 ;;; deopted at script_id: 29 position: 45 with reason 'not a
1909 heap number'.
1910 ;;; Inline point: script_id 30 position: 36.
1911 4 opt_function 29 #4
1912 */
1913 v8::CpuProfile* profile = reinterpret_cast<v8::CpuProfile*>(iprofile);
1914
1915 const char* branch[] = {"", "test"};
1916 const ProfileNode* itest_node =
1917 GetSimpleBranch(env, profile, branch, arraysize(branch));
1918 const std::vector<v8::CpuProfileDeoptInfo>& deopt_infos =
1919 itest_node->deopt_infos();
1920 CHECK_EQ(1U, deopt_infos.size());
1921
1922 const v8::CpuProfileDeoptInfo& info = deopt_infos[0];
1923 CHECK_EQ(reason(i::Deoptimizer::kNotAHeapNumber), info.deopt_reason);
1924 CHECK_EQ(2U, info.stack.size());
1925 CHECK_EQ(inlined_script_id, info.stack[0].script_id);
1926 CHECK_EQ(offset(inlined_source, "left /"), info.stack[0].position);
1927 CHECK_EQ(script_id, info.stack[1].script_id);
1928 CHECK_EQ(offset(source, "opt_function(left,"), info.stack[1].position);
1929
1930 iprofiler->DeleteProfile(iprofile);
1931 }
1932
1933
1934 // deopt at the second level inlined function
TEST(DeoptAtSecondLevelInlinedSource)1935 TEST(DeoptAtSecondLevelInlinedSource) {
1936 if (!CcTest::i_isolate()->use_crankshaft() || i::FLAG_always_opt) return;
1937 i::FLAG_allow_natives_syntax = true;
1938 v8::HandleScope scope(CcTest::isolate());
1939 v8::Local<v8::Context> env = CcTest::NewContext(PROFILER_EXTENSION);
1940 v8::Context::Scope context_scope(env);
1941 v8::Isolate* isolate = env->GetIsolate();
1942 v8::CpuProfiler* profiler = isolate->GetCpuProfiler();
1943 i::CpuProfiler* iprofiler = reinterpret_cast<i::CpuProfiler*>(profiler);
1944
1945 // 0.........1.........2.........3.........4.........5.........6.........7
1946 const char* source =
1947 "function test2(left, right) { return opt_function(left, right); }\n"
1948 "function test1(left, right) { return test2(left, right); }\n"
1949 "\n"
1950 "startProfiling();\n"
1951 "\n"
1952 "test1(10, 10);\n"
1953 "\n"
1954 "%OptimizeFunctionOnNextCall(test1)\n"
1955 "\n"
1956 "test1(10, 10);\n"
1957 "\n"
1958 "test1(undefined, 10);\n"
1959 "\n"
1960 "stopProfiling();\n"
1961 "\n";
1962
1963 v8::Local<v8::Script> inlined_script = v8_compile(inlined_source);
1964 inlined_script->Run(env).ToLocalChecked();
1965 int inlined_script_id = inlined_script->GetUnboundScript()->GetId();
1966
1967 v8::Local<v8::Script> script = v8_compile(source);
1968 script->Run(env).ToLocalChecked();
1969 int script_id = script->GetUnboundScript()->GetId();
1970
1971 i::CpuProfile* iprofile = iprofiler->GetProfile(0);
1972 iprofile->Print();
1973 /* The expected profile output
1974 [Top down]:
1975 0 (root) 0 #1
1976 11 30 #2
1977 1 test1 30 #3
1978 ;;; deopted at script_id: 29 position: 45 with reason 'not a
1979 heap number'.
1980 ;;; Inline point: script_id 30 position: 37.
1981 ;;; Inline point: script_id 30 position: 103.
1982 1 test2 30 #4
1983 3 opt_function 29 #5
1984 */
1985
1986 v8::CpuProfile* profile = reinterpret_cast<v8::CpuProfile*>(iprofile);
1987
1988 const char* branch[] = {"", "test1"};
1989 const ProfileNode* itest_node =
1990 GetSimpleBranch(env, profile, branch, arraysize(branch));
1991 const std::vector<v8::CpuProfileDeoptInfo>& deopt_infos =
1992 itest_node->deopt_infos();
1993 CHECK_EQ(1U, deopt_infos.size());
1994
1995 const v8::CpuProfileDeoptInfo info = deopt_infos[0];
1996 CHECK_EQ(reason(i::Deoptimizer::kNotAHeapNumber), info.deopt_reason);
1997 CHECK_EQ(3U, info.stack.size());
1998 CHECK_EQ(inlined_script_id, info.stack[0].script_id);
1999 CHECK_EQ(offset(inlined_source, "left /"), info.stack[0].position);
2000 CHECK_EQ(script_id, info.stack[1].script_id);
2001 CHECK_EQ(offset(source, "opt_function(left,"), info.stack[1].position);
2002 CHECK_EQ(offset(source, "test2(left, right);"), info.stack[2].position);
2003
2004 iprofiler->DeleteProfile(iprofile);
2005 }
2006
2007
2008 // deopt in untracked function
TEST(DeoptUntrackedFunction)2009 TEST(DeoptUntrackedFunction) {
2010 if (!CcTest::i_isolate()->use_crankshaft() || i::FLAG_always_opt) return;
2011 i::FLAG_allow_natives_syntax = true;
2012 v8::HandleScope scope(CcTest::isolate());
2013 v8::Local<v8::Context> env = CcTest::NewContext(PROFILER_EXTENSION);
2014 v8::Context::Scope context_scope(env);
2015 v8::Isolate* isolate = env->GetIsolate();
2016 v8::CpuProfiler* profiler = isolate->GetCpuProfiler();
2017 i::CpuProfiler* iprofiler = reinterpret_cast<i::CpuProfiler*>(profiler);
2018
2019 // 0.........1.........2.........3.........4.........5.........6.........7
2020 const char* source =
2021 "function test(left, right) { return opt_function(left, right); }\n"
2022 "\n"
2023 "test(10, 10);\n"
2024 "\n"
2025 "%OptimizeFunctionOnNextCall(test)\n"
2026 "\n"
2027 "test(10, 10);\n"
2028 "\n"
2029 "startProfiling();\n" // profiler started after compilation.
2030 "\n"
2031 "test(undefined, 10);\n"
2032 "\n"
2033 "stopProfiling();\n"
2034 "\n";
2035
2036 v8::Local<v8::Script> inlined_script = v8_compile(inlined_source);
2037 inlined_script->Run(env).ToLocalChecked();
2038
2039 v8::Local<v8::Script> script = v8_compile(source);
2040 script->Run(env).ToLocalChecked();
2041
2042 i::CpuProfile* iprofile = iprofiler->GetProfile(0);
2043 iprofile->Print();
2044 v8::CpuProfile* profile = reinterpret_cast<v8::CpuProfile*>(iprofile);
2045
2046 const char* branch[] = {"", "test"};
2047 const ProfileNode* itest_node =
2048 GetSimpleBranch(env, profile, branch, arraysize(branch));
2049 CHECK_EQ(0U, itest_node->deopt_infos().size());
2050
2051 iprofiler->DeleteProfile(iprofile);
2052 }
2053