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 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 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 66 static const char* reason(const i::Deoptimizer::DeoptReason reason) { 67 return i::Deoptimizer::GetDeoptReason(reason); 68 } 69 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 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: 103 TestSetup() 104 : old_flag_prof_browser_mode_(i::FLAG_prof_browser_mode) { 105 i::FLAG_prof_browser_mode = false; 106 } 107 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 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 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> 210 static int CompareProfileNodes(const T* p1, const T* p2) { 211 return strcmp((*p1)->entry()->name(), (*p2)->entry()->name()); 212 } 213 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. 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. 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 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 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 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 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 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 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 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 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 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 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] 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). 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 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 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: 726 explicit TestApiCallbacks(int min_duration_ms) 727 : min_duration_ms_(min_duration_ms), 728 is_warming_up_(false) {} 729 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 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 743 static void Callback(const v8::FunctionCallbackInfo<v8::Value>& info) { 744 TestApiCallbacks* data = FromInfo(info); 745 data->Wait(); 746 } 747 748 void set_warming_up(bool value) { is_warming_up_ = value; } 749 750 private: 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> 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. 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. 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 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 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 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. 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 1100 TEST(TickLinesBaseline) { TickLines(false); } 1101 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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
