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 "v8.h" 31 #include "cpu-profiler-inl.h" 32 #include "cctest.h" 33 #include "platform.h" 34 #include "smart-pointers.h" 35 #include "utils.h" 36 #include "../include/v8-profiler.h" 37 using i::CodeEntry; 38 using i::CpuProfile; 39 using i::CpuProfiler; 40 using i::CpuProfilesCollection; 41 using i::Heap; 42 using i::ProfileGenerator; 43 using i::ProfileNode; 44 using i::ProfilerEventsProcessor; 45 using i::ScopedVector; 46 using i::SmartPointer; 47 using i::TimeDelta; 48 using i::Vector; 49 50 51 TEST(StartStop) { 52 i::Isolate* isolate = CcTest::i_isolate(); 53 CpuProfilesCollection profiles(isolate->heap()); 54 ProfileGenerator generator(&profiles); 55 SmartPointer<ProfilerEventsProcessor> processor(new ProfilerEventsProcessor( 56 &generator, NULL, TimeDelta::FromMicroseconds(100))); 57 processor->Start(); 58 processor->StopSynchronously(); 59 } 60 61 62 static inline i::Address ToAddress(int n) { 63 return reinterpret_cast<i::Address>(n); 64 } 65 66 static void EnqueueTickSampleEvent(ProfilerEventsProcessor* proc, 67 i::Address frame1, 68 i::Address frame2 = NULL, 69 i::Address frame3 = NULL) { 70 i::TickSample* sample = proc->StartTickSample(); 71 sample->pc = frame1; 72 sample->tos = frame1; 73 sample->frames_count = 0; 74 if (frame2 != NULL) { 75 sample->stack[0] = frame2; 76 sample->frames_count = 1; 77 } 78 if (frame3 != NULL) { 79 sample->stack[1] = frame3; 80 sample->frames_count = 2; 81 } 82 proc->FinishTickSample(); 83 } 84 85 namespace { 86 87 class TestSetup { 88 public: 89 TestSetup() 90 : old_flag_prof_browser_mode_(i::FLAG_prof_browser_mode) { 91 i::FLAG_prof_browser_mode = false; 92 } 93 94 ~TestSetup() { 95 i::FLAG_prof_browser_mode = old_flag_prof_browser_mode_; 96 } 97 98 private: 99 bool old_flag_prof_browser_mode_; 100 }; 101 102 } // namespace 103 104 105 i::Code* CreateCode(LocalContext* env) { 106 static int counter = 0; 107 i::EmbeddedVector<char, 256> script; 108 i::EmbeddedVector<char, 32> name; 109 110 i::OS::SNPrintF(name, "function_%d", ++counter); 111 const char* name_start = name.start(); 112 i::OS::SNPrintF(script, 113 "function %s() {\n" 114 "var counter = 0;\n" 115 "for (var i = 0; i < %d; ++i) counter += i;\n" 116 "return '%s_' + counter;\n" 117 "}\n" 118 "%s();\n", name_start, counter, name_start, name_start); 119 CompileRun(script.start()); 120 i::Handle<i::JSFunction> fun = v8::Utils::OpenHandle( 121 *v8::Local<v8::Function>::Cast( 122 (*env)->Global()->Get(v8_str(name_start)))); 123 return fun->code(); 124 } 125 126 127 TEST(CodeEvents) { 128 CcTest::InitializeVM(); 129 LocalContext env; 130 i::Isolate* isolate = CcTest::i_isolate(); 131 i::Factory* factory = isolate->factory(); 132 TestSetup test_setup; 133 134 i::HandleScope scope(isolate); 135 136 i::Code* aaa_code = CreateCode(&env); 137 i::Code* comment_code = CreateCode(&env); 138 i::Code* args5_code = CreateCode(&env); 139 i::Code* comment2_code = CreateCode(&env); 140 i::Code* moved_code = CreateCode(&env); 141 i::Code* args3_code = CreateCode(&env); 142 i::Code* args4_code = CreateCode(&env); 143 144 CpuProfilesCollection* profiles = new CpuProfilesCollection(isolate->heap()); 145 profiles->StartProfiling("", 1, false); 146 ProfileGenerator generator(profiles); 147 SmartPointer<ProfilerEventsProcessor> processor(new ProfilerEventsProcessor( 148 &generator, NULL, TimeDelta::FromMicroseconds(100))); 149 processor->Start(); 150 CpuProfiler profiler(isolate, profiles, &generator, *processor); 151 152 // Enqueue code creation events. 153 const char* aaa_str = "aaa"; 154 i::Handle<i::String> aaa_name = factory->NewStringFromAscii( 155 i::Vector<const char>(aaa_str, i::StrLength(aaa_str))); 156 profiler.CodeCreateEvent(i::Logger::FUNCTION_TAG, aaa_code, *aaa_name); 157 profiler.CodeCreateEvent(i::Logger::BUILTIN_TAG, comment_code, "comment"); 158 profiler.CodeCreateEvent(i::Logger::STUB_TAG, args5_code, 5); 159 profiler.CodeCreateEvent(i::Logger::BUILTIN_TAG, comment2_code, "comment2"); 160 profiler.CodeMoveEvent(comment2_code->address(), moved_code->address()); 161 profiler.CodeCreateEvent(i::Logger::STUB_TAG, args3_code, 3); 162 profiler.CodeCreateEvent(i::Logger::STUB_TAG, args4_code, 4); 163 164 // Enqueue a tick event to enable code events processing. 165 EnqueueTickSampleEvent(*processor, aaa_code->address()); 166 167 processor->StopSynchronously(); 168 169 // Check the state of profile generator. 170 CodeEntry* aaa = generator.code_map()->FindEntry(aaa_code->address()); 171 CHECK_NE(NULL, aaa); 172 CHECK_EQ(aaa_str, aaa->name()); 173 174 CodeEntry* comment = generator.code_map()->FindEntry(comment_code->address()); 175 CHECK_NE(NULL, comment); 176 CHECK_EQ("comment", comment->name()); 177 178 CodeEntry* args5 = generator.code_map()->FindEntry(args5_code->address()); 179 CHECK_NE(NULL, args5); 180 CHECK_EQ("5", args5->name()); 181 182 CHECK_EQ(NULL, generator.code_map()->FindEntry(comment2_code->address())); 183 184 CodeEntry* comment2 = generator.code_map()->FindEntry(moved_code->address()); 185 CHECK_NE(NULL, comment2); 186 CHECK_EQ("comment2", comment2->name()); 187 } 188 189 190 template<typename T> 191 static int CompareProfileNodes(const T* p1, const T* p2) { 192 return strcmp((*p1)->entry()->name(), (*p2)->entry()->name()); 193 } 194 195 196 TEST(TickEvents) { 197 TestSetup test_setup; 198 LocalContext env; 199 i::Isolate* isolate = CcTest::i_isolate(); 200 i::HandleScope scope(isolate); 201 202 i::Code* frame1_code = CreateCode(&env); 203 i::Code* frame2_code = CreateCode(&env); 204 i::Code* frame3_code = CreateCode(&env); 205 206 CpuProfilesCollection* profiles = new CpuProfilesCollection(isolate->heap()); 207 profiles->StartProfiling("", 1, false); 208 ProfileGenerator generator(profiles); 209 SmartPointer<ProfilerEventsProcessor> processor(new ProfilerEventsProcessor( 210 &generator, NULL, TimeDelta::FromMicroseconds(100))); 211 processor->Start(); 212 CpuProfiler profiler(isolate, profiles, &generator, *processor); 213 214 profiler.CodeCreateEvent(i::Logger::BUILTIN_TAG, frame1_code, "bbb"); 215 profiler.CodeCreateEvent(i::Logger::STUB_TAG, frame2_code, 5); 216 profiler.CodeCreateEvent(i::Logger::BUILTIN_TAG, frame3_code, "ddd"); 217 218 EnqueueTickSampleEvent(*processor, frame1_code->instruction_start()); 219 EnqueueTickSampleEvent( 220 *processor, 221 frame2_code->instruction_start() + frame2_code->ExecutableSize() / 2, 222 frame1_code->instruction_start() + frame2_code->ExecutableSize() / 2); 223 EnqueueTickSampleEvent( 224 *processor, 225 frame3_code->instruction_end() - 1, 226 frame2_code->instruction_end() - 1, 227 frame1_code->instruction_end() - 1); 228 229 processor->StopSynchronously(); 230 CpuProfile* profile = profiles->StopProfiling(""); 231 CHECK_NE(NULL, profile); 232 233 // Check call trees. 234 const i::List<ProfileNode*>* top_down_root_children = 235 profile->top_down()->root()->children(); 236 CHECK_EQ(1, top_down_root_children->length()); 237 CHECK_EQ("bbb", top_down_root_children->last()->entry()->name()); 238 const i::List<ProfileNode*>* top_down_bbb_children = 239 top_down_root_children->last()->children(); 240 CHECK_EQ(1, top_down_bbb_children->length()); 241 CHECK_EQ("5", top_down_bbb_children->last()->entry()->name()); 242 const i::List<ProfileNode*>* top_down_stub_children = 243 top_down_bbb_children->last()->children(); 244 CHECK_EQ(1, top_down_stub_children->length()); 245 CHECK_EQ("ddd", top_down_stub_children->last()->entry()->name()); 246 const i::List<ProfileNode*>* top_down_ddd_children = 247 top_down_stub_children->last()->children(); 248 CHECK_EQ(0, top_down_ddd_children->length()); 249 } 250 251 252 // http://crbug/51594 253 // This test must not crash. 254 TEST(CrashIfStoppingLastNonExistentProfile) { 255 CcTest::InitializeVM(); 256 TestSetup test_setup; 257 CpuProfiler* profiler = CcTest::i_isolate()->cpu_profiler(); 258 profiler->StartProfiling("1"); 259 profiler->StopProfiling("2"); 260 profiler->StartProfiling("1"); 261 profiler->StopProfiling(""); 262 } 263 264 265 // http://code.google.com/p/v8/issues/detail?id=1398 266 // Long stacks (exceeding max frames limit) must not be erased. 267 TEST(Issue1398) { 268 TestSetup test_setup; 269 LocalContext env; 270 i::Isolate* isolate = CcTest::i_isolate(); 271 i::HandleScope scope(isolate); 272 273 i::Code* code = CreateCode(&env); 274 275 CpuProfilesCollection* profiles = new CpuProfilesCollection(isolate->heap()); 276 profiles->StartProfiling("", 1, false); 277 ProfileGenerator generator(profiles); 278 SmartPointer<ProfilerEventsProcessor> processor(new ProfilerEventsProcessor( 279 &generator, NULL, TimeDelta::FromMicroseconds(100))); 280 processor->Start(); 281 CpuProfiler profiler(isolate, profiles, &generator, *processor); 282 283 profiler.CodeCreateEvent(i::Logger::BUILTIN_TAG, code, "bbb"); 284 285 i::TickSample* sample = processor->StartTickSample(); 286 sample->pc = code->address(); 287 sample->tos = 0; 288 sample->frames_count = i::TickSample::kMaxFramesCount; 289 for (int i = 0; i < sample->frames_count; ++i) { 290 sample->stack[i] = code->address(); 291 } 292 processor->FinishTickSample(); 293 294 processor->StopSynchronously(); 295 CpuProfile* profile = profiles->StopProfiling(""); 296 CHECK_NE(NULL, profile); 297 298 int actual_depth = 0; 299 const ProfileNode* node = profile->top_down()->root(); 300 while (node->children()->length() > 0) { 301 node = node->children()->last(); 302 ++actual_depth; 303 } 304 305 CHECK_EQ(1 + i::TickSample::kMaxFramesCount, actual_depth); // +1 for PC. 306 } 307 308 309 TEST(DeleteAllCpuProfiles) { 310 CcTest::InitializeVM(); 311 TestSetup test_setup; 312 CpuProfiler* profiler = CcTest::i_isolate()->cpu_profiler(); 313 CHECK_EQ(0, profiler->GetProfilesCount()); 314 profiler->DeleteAllProfiles(); 315 CHECK_EQ(0, profiler->GetProfilesCount()); 316 317 profiler->StartProfiling("1"); 318 profiler->StopProfiling("1"); 319 CHECK_EQ(1, profiler->GetProfilesCount()); 320 profiler->DeleteAllProfiles(); 321 CHECK_EQ(0, profiler->GetProfilesCount()); 322 profiler->StartProfiling("1"); 323 profiler->StartProfiling("2"); 324 profiler->StopProfiling("2"); 325 profiler->StopProfiling("1"); 326 CHECK_EQ(2, profiler->GetProfilesCount()); 327 profiler->DeleteAllProfiles(); 328 CHECK_EQ(0, profiler->GetProfilesCount()); 329 330 // Test profiling cancellation by the 'delete' command. 331 profiler->StartProfiling("1"); 332 profiler->StartProfiling("2"); 333 CHECK_EQ(0, profiler->GetProfilesCount()); 334 profiler->DeleteAllProfiles(); 335 CHECK_EQ(0, profiler->GetProfilesCount()); 336 } 337 338 339 static const v8::CpuProfile* FindCpuProfile(v8::CpuProfiler* profiler, 340 unsigned uid) { 341 int length = profiler->GetProfileCount(); 342 for (int i = 0; i < length; i++) { 343 const v8::CpuProfile* profile = profiler->GetCpuProfile(i); 344 if (profile->GetUid() == uid) { 345 return profile; 346 } 347 } 348 return NULL; 349 } 350 351 352 TEST(DeleteCpuProfile) { 353 LocalContext env; 354 v8::HandleScope scope(env->GetIsolate()); 355 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler(); 356 357 CHECK_EQ(0, cpu_profiler->GetProfileCount()); 358 v8::Local<v8::String> name1 = v8::String::NewFromUtf8(env->GetIsolate(), "1"); 359 cpu_profiler->StartCpuProfiling(name1); 360 const v8::CpuProfile* p1 = cpu_profiler->StopCpuProfiling(name1); 361 CHECK_NE(NULL, p1); 362 CHECK_EQ(1, cpu_profiler->GetProfileCount()); 363 unsigned uid1 = p1->GetUid(); 364 CHECK_EQ(p1, FindCpuProfile(cpu_profiler, uid1)); 365 const_cast<v8::CpuProfile*>(p1)->Delete(); 366 CHECK_EQ(0, cpu_profiler->GetProfileCount()); 367 CHECK_EQ(NULL, FindCpuProfile(cpu_profiler, uid1)); 368 369 v8::Local<v8::String> name2 = v8::String::NewFromUtf8(env->GetIsolate(), "2"); 370 cpu_profiler->StartCpuProfiling(name2); 371 const v8::CpuProfile* p2 = cpu_profiler->StopCpuProfiling(name2); 372 CHECK_NE(NULL, p2); 373 CHECK_EQ(1, cpu_profiler->GetProfileCount()); 374 unsigned uid2 = p2->GetUid(); 375 CHECK_NE(static_cast<int>(uid1), static_cast<int>(uid2)); 376 CHECK_EQ(p2, FindCpuProfile(cpu_profiler, uid2)); 377 CHECK_EQ(NULL, FindCpuProfile(cpu_profiler, uid1)); 378 v8::Local<v8::String> name3 = v8::String::NewFromUtf8(env->GetIsolate(), "3"); 379 cpu_profiler->StartCpuProfiling(name3); 380 const v8::CpuProfile* p3 = cpu_profiler->StopCpuProfiling(name3); 381 CHECK_NE(NULL, p3); 382 CHECK_EQ(2, cpu_profiler->GetProfileCount()); 383 unsigned uid3 = p3->GetUid(); 384 CHECK_NE(static_cast<int>(uid1), static_cast<int>(uid3)); 385 CHECK_EQ(p3, FindCpuProfile(cpu_profiler, uid3)); 386 CHECK_EQ(NULL, FindCpuProfile(cpu_profiler, uid1)); 387 const_cast<v8::CpuProfile*>(p2)->Delete(); 388 CHECK_EQ(1, cpu_profiler->GetProfileCount()); 389 CHECK_EQ(NULL, FindCpuProfile(cpu_profiler, uid2)); 390 CHECK_EQ(p3, FindCpuProfile(cpu_profiler, uid3)); 391 const_cast<v8::CpuProfile*>(p3)->Delete(); 392 CHECK_EQ(0, cpu_profiler->GetProfileCount()); 393 CHECK_EQ(NULL, FindCpuProfile(cpu_profiler, uid3)); 394 CHECK_EQ(NULL, FindCpuProfile(cpu_profiler, uid2)); 395 CHECK_EQ(NULL, FindCpuProfile(cpu_profiler, uid1)); 396 } 397 398 399 TEST(ProfileStartEndTime) { 400 LocalContext env; 401 v8::HandleScope scope(env->GetIsolate()); 402 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler(); 403 404 v8::Local<v8::String> profile_name = 405 v8::String::NewFromUtf8(env->GetIsolate(), "test"); 406 cpu_profiler->StartCpuProfiling(profile_name); 407 const v8::CpuProfile* profile = cpu_profiler->StopCpuProfiling(profile_name); 408 CHECK(profile->GetStartTime() <= profile->GetEndTime()); 409 } 410 411 412 static const v8::CpuProfile* RunProfiler( 413 LocalContext& env, v8::Handle<v8::Function> function, 414 v8::Handle<v8::Value> argv[], int argc, 415 unsigned min_js_samples) { 416 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler(); 417 v8::Local<v8::String> profile_name = 418 v8::String::NewFromUtf8(env->GetIsolate(), "my_profile"); 419 420 cpu_profiler->StartCpuProfiling(profile_name); 421 422 i::Sampler* sampler = 423 reinterpret_cast<i::Isolate*>(env->GetIsolate())->logger()->sampler(); 424 sampler->StartCountingSamples(); 425 do { 426 function->Call(env->Global(), argc, argv); 427 } while (sampler->js_and_external_sample_count() < min_js_samples); 428 429 const v8::CpuProfile* profile = cpu_profiler->StopCpuProfiling(profile_name); 430 431 CHECK_NE(NULL, profile); 432 // Dump collected profile to have a better diagnostic in case of failure. 433 reinterpret_cast<i::CpuProfile*>( 434 const_cast<v8::CpuProfile*>(profile))->Print(); 435 436 return profile; 437 } 438 439 440 static bool ContainsString(v8::Handle<v8::String> string, 441 const Vector<v8::Handle<v8::String> >& vector) { 442 for (int i = 0; i < vector.length(); i++) { 443 if (string->Equals(vector[i])) 444 return true; 445 } 446 return false; 447 } 448 449 450 static void CheckChildrenNames(const v8::CpuProfileNode* node, 451 const Vector<v8::Handle<v8::String> >& names) { 452 int count = node->GetChildrenCount(); 453 for (int i = 0; i < count; i++) { 454 v8::Handle<v8::String> name = node->GetChild(i)->GetFunctionName(); 455 CHECK(ContainsString(name, names)); 456 // Check that there are no duplicates. 457 for (int j = 0; j < count; j++) { 458 if (j == i) continue; 459 CHECK_NE(name, node->GetChild(j)->GetFunctionName()); 460 } 461 } 462 } 463 464 465 static const v8::CpuProfileNode* FindChild(v8::Isolate* isolate, 466 const v8::CpuProfileNode* node, 467 const char* name) { 468 int count = node->GetChildrenCount(); 469 v8::Handle<v8::String> nameHandle = v8::String::NewFromUtf8(isolate, name); 470 for (int i = 0; i < count; i++) { 471 const v8::CpuProfileNode* child = node->GetChild(i); 472 if (nameHandle->Equals(child->GetFunctionName())) return child; 473 } 474 return NULL; 475 } 476 477 478 static const v8::CpuProfileNode* GetChild(v8::Isolate* isolate, 479 const v8::CpuProfileNode* node, 480 const char* name) { 481 const v8::CpuProfileNode* result = FindChild(isolate, node, name); 482 if (!result) { 483 char buffer[100]; 484 i::OS::SNPrintF(Vector<char>(buffer, ARRAY_SIZE(buffer)), 485 "Failed to GetChild: %s", name); 486 FATAL(buffer); 487 } 488 return result; 489 } 490 491 492 static void CheckSimpleBranch(v8::Isolate* isolate, 493 const v8::CpuProfileNode* node, 494 const char* names[], int length) { 495 for (int i = 0; i < length; i++) { 496 const char* name = names[i]; 497 node = GetChild(isolate, node, name); 498 int expectedChildrenCount = (i == length - 1) ? 0 : 1; 499 CHECK_EQ(expectedChildrenCount, node->GetChildrenCount()); 500 } 501 } 502 503 504 static const char* cpu_profiler_test_source = "function loop(timeout) {\n" 505 " this.mmm = 0;\n" 506 " var start = Date.now();\n" 507 " while (Date.now() - start < timeout) {\n" 508 " var n = 100*1000;\n" 509 " while(n > 1) {\n" 510 " n--;\n" 511 " this.mmm += n * n * n;\n" 512 " }\n" 513 " }\n" 514 "}\n" 515 "function delay() { try { loop(10); } catch(e) { } }\n" 516 "function bar() { delay(); }\n" 517 "function baz() { delay(); }\n" 518 "function foo() {\n" 519 " try {\n" 520 " delay();\n" 521 " bar();\n" 522 " delay();\n" 523 " baz();\n" 524 " } catch (e) { }\n" 525 "}\n" 526 "function start(timeout) {\n" 527 " var start = Date.now();\n" 528 " do {\n" 529 " foo();\n" 530 " var duration = Date.now() - start;\n" 531 " } while (duration < timeout);\n" 532 " return duration;\n" 533 "}\n"; 534 535 536 // Check that the profile tree for the script above will look like the 537 // following: 538 // 539 // [Top down]: 540 // 1062 0 (root) [-1] 541 // 1054 0 start [-1] 542 // 1054 1 foo [-1] 543 // 265 0 baz [-1] 544 // 265 1 delay [-1] 545 // 264 264 loop [-1] 546 // 525 3 delay [-1] 547 // 522 522 loop [-1] 548 // 263 0 bar [-1] 549 // 263 1 delay [-1] 550 // 262 262 loop [-1] 551 // 2 2 (program) [-1] 552 // 6 6 (garbage collector) [-1] 553 TEST(CollectCpuProfile) { 554 LocalContext env; 555 v8::HandleScope scope(env->GetIsolate()); 556 557 v8::Script::Compile(v8::String::NewFromUtf8(env->GetIsolate(), 558 cpu_profiler_test_source))->Run(); 559 v8::Local<v8::Function> function = v8::Local<v8::Function>::Cast( 560 env->Global()->Get(v8::String::NewFromUtf8(env->GetIsolate(), "start"))); 561 562 int32_t profiling_interval_ms = 200; 563 v8::Handle<v8::Value> args[] = { v8::Integer::New(profiling_interval_ms) }; 564 const v8::CpuProfile* profile = 565 RunProfiler(env, function, args, ARRAY_SIZE(args), 200); 566 function->Call(env->Global(), ARRAY_SIZE(args), args); 567 568 const v8::CpuProfileNode* root = profile->GetTopDownRoot(); 569 570 ScopedVector<v8::Handle<v8::String> > names(3); 571 names[0] = v8::String::NewFromUtf8( 572 env->GetIsolate(), ProfileGenerator::kGarbageCollectorEntryName); 573 names[1] = v8::String::NewFromUtf8(env->GetIsolate(), 574 ProfileGenerator::kProgramEntryName); 575 names[2] = v8::String::NewFromUtf8(env->GetIsolate(), "start"); 576 CheckChildrenNames(root, names); 577 578 const v8::CpuProfileNode* startNode = 579 GetChild(env->GetIsolate(), root, "start"); 580 CHECK_EQ(1, startNode->GetChildrenCount()); 581 582 const v8::CpuProfileNode* fooNode = 583 GetChild(env->GetIsolate(), startNode, "foo"); 584 CHECK_EQ(3, fooNode->GetChildrenCount()); 585 586 const char* barBranch[] = { "bar", "delay", "loop" }; 587 CheckSimpleBranch(env->GetIsolate(), fooNode, barBranch, 588 ARRAY_SIZE(barBranch)); 589 const char* bazBranch[] = { "baz", "delay", "loop" }; 590 CheckSimpleBranch(env->GetIsolate(), fooNode, bazBranch, 591 ARRAY_SIZE(bazBranch)); 592 const char* delayBranch[] = { "delay", "loop" }; 593 CheckSimpleBranch(env->GetIsolate(), fooNode, delayBranch, 594 ARRAY_SIZE(delayBranch)); 595 596 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler(); 597 cpu_profiler->DeleteAllCpuProfiles(); 598 } 599 600 601 602 static const char* cpu_profiler_test_source2 = "function loop() {}\n" 603 "function delay() { loop(); }\n" 604 "function start(count) {\n" 605 " var k = 0;\n" 606 " do {\n" 607 " delay();\n" 608 " } while (++k < count*100*1000);\n" 609 "}\n"; 610 611 // Check that the profile tree doesn't contain unexpected traces: 612 // - 'loop' can be called only by 'delay' 613 // - 'delay' may be called only by 'start' 614 // The profile will look like the following: 615 // 616 // [Top down]: 617 // 135 0 (root) [-1] #1 618 // 121 72 start [-1] #3 619 // 49 33 delay [-1] #4 620 // 16 16 loop [-1] #5 621 // 14 14 (program) [-1] #2 622 TEST(SampleWhenFrameIsNotSetup) { 623 LocalContext env; 624 v8::HandleScope scope(env->GetIsolate()); 625 626 v8::Script::Compile(v8::String::NewFromUtf8( 627 env->GetIsolate(), cpu_profiler_test_source2))->Run(); 628 v8::Local<v8::Function> function = v8::Local<v8::Function>::Cast( 629 env->Global()->Get(v8::String::NewFromUtf8(env->GetIsolate(), "start"))); 630 631 int32_t repeat_count = 100; 632 #if defined(USE_SIMULATOR) 633 // Simulators are much slower. 634 repeat_count = 1; 635 #endif 636 v8::Handle<v8::Value> args[] = { v8::Integer::New(repeat_count) }; 637 const v8::CpuProfile* profile = 638 RunProfiler(env, function, args, ARRAY_SIZE(args), 100); 639 640 const v8::CpuProfileNode* root = profile->GetTopDownRoot(); 641 642 ScopedVector<v8::Handle<v8::String> > names(3); 643 names[0] = v8::String::NewFromUtf8( 644 env->GetIsolate(), ProfileGenerator::kGarbageCollectorEntryName); 645 names[1] = v8::String::NewFromUtf8(env->GetIsolate(), 646 ProfileGenerator::kProgramEntryName); 647 names[2] = v8::String::NewFromUtf8(env->GetIsolate(), "start"); 648 CheckChildrenNames(root, names); 649 650 const v8::CpuProfileNode* startNode = 651 FindChild(env->GetIsolate(), root, "start"); 652 // On slow machines there may be no meaningfull samples at all, skip the 653 // check there. 654 if (startNode && startNode->GetChildrenCount() > 0) { 655 CHECK_EQ(1, startNode->GetChildrenCount()); 656 const v8::CpuProfileNode* delayNode = 657 GetChild(env->GetIsolate(), startNode, "delay"); 658 if (delayNode->GetChildrenCount() > 0) { 659 CHECK_EQ(1, delayNode->GetChildrenCount()); 660 GetChild(env->GetIsolate(), delayNode, "loop"); 661 } 662 } 663 664 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler(); 665 cpu_profiler->DeleteAllCpuProfiles(); 666 } 667 668 669 static const char* native_accessor_test_source = "function start(count) {\n" 670 " for (var i = 0; i < count; i++) {\n" 671 " var o = instance.foo;\n" 672 " instance.foo = o + 1;\n" 673 " }\n" 674 "}\n"; 675 676 677 class TestApiCallbacks { 678 public: 679 explicit TestApiCallbacks(int min_duration_ms) 680 : min_duration_ms_(min_duration_ms), 681 is_warming_up_(false) {} 682 683 static void Getter(v8::Local<v8::String> name, 684 const v8::PropertyCallbackInfo<v8::Value>& info) { 685 TestApiCallbacks* data = fromInfo(info); 686 data->Wait(); 687 } 688 689 static void Setter(v8::Local<v8::String> name, 690 v8::Local<v8::Value> value, 691 const v8::PropertyCallbackInfo<void>& info) { 692 TestApiCallbacks* data = fromInfo(info); 693 data->Wait(); 694 } 695 696 static void Callback(const v8::FunctionCallbackInfo<v8::Value>& info) { 697 TestApiCallbacks* data = fromInfo(info); 698 data->Wait(); 699 } 700 701 void set_warming_up(bool value) { is_warming_up_ = value; } 702 703 private: 704 void Wait() { 705 if (is_warming_up_) return; 706 double start = i::OS::TimeCurrentMillis(); 707 double duration = 0; 708 while (duration < min_duration_ms_) { 709 i::OS::Sleep(1); 710 duration = i::OS::TimeCurrentMillis() - start; 711 } 712 } 713 714 template<typename T> 715 static TestApiCallbacks* fromInfo(const T& info) { 716 void* data = v8::External::Cast(*info.Data())->Value(); 717 return reinterpret_cast<TestApiCallbacks*>(data); 718 } 719 720 int min_duration_ms_; 721 bool is_warming_up_; 722 }; 723 724 725 // Test that native accessors are properly reported in the CPU profile. 726 // This test checks the case when the long-running accessors are called 727 // only once and the optimizer doesn't have chance to change the invocation 728 // code. 729 TEST(NativeAccessorUninitializedIC) { 730 LocalContext env; 731 v8::HandleScope scope(env->GetIsolate()); 732 733 734 v8::Local<v8::FunctionTemplate> func_template = v8::FunctionTemplate::New(); 735 v8::Local<v8::ObjectTemplate> instance_template = 736 func_template->InstanceTemplate(); 737 738 TestApiCallbacks accessors(100); 739 v8::Local<v8::External> data = 740 v8::External::New(env->GetIsolate(), &accessors); 741 instance_template->SetAccessor( 742 v8::String::NewFromUtf8(env->GetIsolate(), "foo"), 743 &TestApiCallbacks::Getter, &TestApiCallbacks::Setter, data); 744 v8::Local<v8::Function> func = func_template->GetFunction(); 745 v8::Local<v8::Object> instance = func->NewInstance(); 746 env->Global()->Set(v8::String::NewFromUtf8(env->GetIsolate(), "instance"), 747 instance); 748 749 v8::Script::Compile( 750 v8::String::NewFromUtf8(env->GetIsolate(), native_accessor_test_source)) 751 ->Run(); 752 v8::Local<v8::Function> function = v8::Local<v8::Function>::Cast( 753 env->Global()->Get(v8::String::NewFromUtf8(env->GetIsolate(), "start"))); 754 755 int32_t repeat_count = 1; 756 v8::Handle<v8::Value> args[] = { v8::Integer::New(repeat_count) }; 757 const v8::CpuProfile* profile = 758 RunProfiler(env, function, args, ARRAY_SIZE(args), 180); 759 760 const v8::CpuProfileNode* root = profile->GetTopDownRoot(); 761 const v8::CpuProfileNode* startNode = 762 GetChild(env->GetIsolate(), root, "start"); 763 GetChild(env->GetIsolate(), startNode, "get foo"); 764 GetChild(env->GetIsolate(), startNode, "set foo"); 765 766 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler(); 767 cpu_profiler->DeleteAllCpuProfiles(); 768 } 769 770 771 // Test that native accessors are properly reported in the CPU profile. 772 // This test makes sure that the accessors are called enough times to become 773 // hot and to trigger optimizations. 774 TEST(NativeAccessorMonomorphicIC) { 775 LocalContext env; 776 v8::HandleScope scope(env->GetIsolate()); 777 778 779 v8::Local<v8::FunctionTemplate> func_template = v8::FunctionTemplate::New(); 780 v8::Local<v8::ObjectTemplate> instance_template = 781 func_template->InstanceTemplate(); 782 783 TestApiCallbacks accessors(1); 784 v8::Local<v8::External> data = 785 v8::External::New(env->GetIsolate(), &accessors); 786 instance_template->SetAccessor( 787 v8::String::NewFromUtf8(env->GetIsolate(), "foo"), 788 &TestApiCallbacks::Getter, &TestApiCallbacks::Setter, data); 789 v8::Local<v8::Function> func = func_template->GetFunction(); 790 v8::Local<v8::Object> instance = func->NewInstance(); 791 env->Global()->Set(v8::String::NewFromUtf8(env->GetIsolate(), "instance"), 792 instance); 793 794 v8::Script::Compile( 795 v8::String::NewFromUtf8(env->GetIsolate(), native_accessor_test_source)) 796 ->Run(); 797 v8::Local<v8::Function> function = v8::Local<v8::Function>::Cast( 798 env->Global()->Get(v8::String::NewFromUtf8(env->GetIsolate(), "start"))); 799 800 { 801 // Make sure accessors ICs are in monomorphic state before starting 802 // profiling. 803 accessors.set_warming_up(true); 804 int32_t warm_up_iterations = 3; 805 v8::Handle<v8::Value> args[] = { v8::Integer::New(warm_up_iterations) }; 806 function->Call(env->Global(), ARRAY_SIZE(args), args); 807 accessors.set_warming_up(false); 808 } 809 810 int32_t repeat_count = 100; 811 v8::Handle<v8::Value> args[] = { v8::Integer::New(repeat_count) }; 812 const v8::CpuProfile* profile = 813 RunProfiler(env, function, args, ARRAY_SIZE(args), 200); 814 815 const v8::CpuProfileNode* root = profile->GetTopDownRoot(); 816 const v8::CpuProfileNode* startNode = 817 GetChild(env->GetIsolate(), root, "start"); 818 GetChild(env->GetIsolate(), startNode, "get foo"); 819 GetChild(env->GetIsolate(), startNode, "set foo"); 820 821 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler(); 822 cpu_profiler->DeleteAllCpuProfiles(); 823 } 824 825 826 static const char* native_method_test_source = "function start(count) {\n" 827 " for (var i = 0; i < count; i++) {\n" 828 " instance.fooMethod();\n" 829 " }\n" 830 "}\n"; 831 832 833 TEST(NativeMethodUninitializedIC) { 834 LocalContext env; 835 v8::HandleScope scope(env->GetIsolate()); 836 837 TestApiCallbacks callbacks(100); 838 v8::Local<v8::External> data = 839 v8::External::New(env->GetIsolate(), &callbacks); 840 841 v8::Local<v8::FunctionTemplate> func_template = v8::FunctionTemplate::New(); 842 func_template->SetClassName( 843 v8::String::NewFromUtf8(env->GetIsolate(), "Test_InstanceCostructor")); 844 v8::Local<v8::ObjectTemplate> proto_template = 845 func_template->PrototypeTemplate(); 846 v8::Local<v8::Signature> signature = 847 v8::Signature::New(env->GetIsolate(), func_template); 848 proto_template->Set(v8::String::NewFromUtf8(env->GetIsolate(), "fooMethod"), 849 v8::FunctionTemplate::New(&TestApiCallbacks::Callback, 850 data, signature, 0)); 851 852 v8::Local<v8::Function> func = func_template->GetFunction(); 853 v8::Local<v8::Object> instance = func->NewInstance(); 854 env->Global()->Set(v8::String::NewFromUtf8(env->GetIsolate(), "instance"), 855 instance); 856 857 v8::Script::Compile(v8::String::NewFromUtf8( 858 env->GetIsolate(), native_method_test_source))->Run(); 859 v8::Local<v8::Function> function = v8::Local<v8::Function>::Cast( 860 env->Global()->Get(v8::String::NewFromUtf8(env->GetIsolate(), "start"))); 861 862 int32_t repeat_count = 1; 863 v8::Handle<v8::Value> args[] = { v8::Integer::New(repeat_count) }; 864 const v8::CpuProfile* profile = 865 RunProfiler(env, function, args, ARRAY_SIZE(args), 100); 866 867 const v8::CpuProfileNode* root = profile->GetTopDownRoot(); 868 const v8::CpuProfileNode* startNode = 869 GetChild(env->GetIsolate(), root, "start"); 870 GetChild(env->GetIsolate(), startNode, "fooMethod"); 871 872 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler(); 873 cpu_profiler->DeleteAllCpuProfiles(); 874 } 875 876 877 TEST(NativeMethodMonomorphicIC) { 878 LocalContext env; 879 v8::HandleScope scope(env->GetIsolate()); 880 881 TestApiCallbacks callbacks(1); 882 v8::Local<v8::External> data = 883 v8::External::New(env->GetIsolate(), &callbacks); 884 885 v8::Local<v8::FunctionTemplate> func_template = v8::FunctionTemplate::New(); 886 func_template->SetClassName( 887 v8::String::NewFromUtf8(env->GetIsolate(), "Test_InstanceCostructor")); 888 v8::Local<v8::ObjectTemplate> proto_template = 889 func_template->PrototypeTemplate(); 890 v8::Local<v8::Signature> signature = 891 v8::Signature::New(env->GetIsolate(), func_template); 892 proto_template->Set(v8::String::NewFromUtf8(env->GetIsolate(), "fooMethod"), 893 v8::FunctionTemplate::New(&TestApiCallbacks::Callback, 894 data, signature, 0)); 895 896 v8::Local<v8::Function> func = func_template->GetFunction(); 897 v8::Local<v8::Object> instance = func->NewInstance(); 898 env->Global()->Set(v8::String::NewFromUtf8(env->GetIsolate(), "instance"), 899 instance); 900 901 v8::Script::Compile(v8::String::NewFromUtf8( 902 env->GetIsolate(), native_method_test_source))->Run(); 903 v8::Local<v8::Function> function = v8::Local<v8::Function>::Cast( 904 env->Global()->Get(v8::String::NewFromUtf8(env->GetIsolate(), "start"))); 905 { 906 // Make sure method ICs are in monomorphic state before starting 907 // profiling. 908 callbacks.set_warming_up(true); 909 int32_t warm_up_iterations = 3; 910 v8::Handle<v8::Value> args[] = { v8::Integer::New(warm_up_iterations) }; 911 function->Call(env->Global(), ARRAY_SIZE(args), args); 912 callbacks.set_warming_up(false); 913 } 914 915 int32_t repeat_count = 100; 916 v8::Handle<v8::Value> args[] = { v8::Integer::New(repeat_count) }; 917 const v8::CpuProfile* profile = 918 RunProfiler(env, function, args, ARRAY_SIZE(args), 100); 919 920 const v8::CpuProfileNode* root = profile->GetTopDownRoot(); 921 GetChild(env->GetIsolate(), root, "start"); 922 const v8::CpuProfileNode* startNode = 923 GetChild(env->GetIsolate(), root, "start"); 924 GetChild(env->GetIsolate(), startNode, "fooMethod"); 925 926 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler(); 927 cpu_profiler->DeleteAllCpuProfiles(); 928 } 929 930 931 static const char* bound_function_test_source = "function foo(iterations) {\n" 932 " var r = 0;\n" 933 " for (var i = 0; i < iterations; i++) { r += i; }\n" 934 " return r;\n" 935 "}\n" 936 "function start(duration) {\n" 937 " var callback = foo.bind(this);\n" 938 " var start = Date.now();\n" 939 " while (Date.now() - start < duration) {\n" 940 " callback(10 * 1000);\n" 941 " }\n" 942 "}"; 943 944 945 TEST(BoundFunctionCall) { 946 LocalContext env; 947 v8::HandleScope scope(env->GetIsolate()); 948 949 v8::Script::Compile( 950 v8::String::NewFromUtf8(env->GetIsolate(), bound_function_test_source)) 951 ->Run(); 952 v8::Local<v8::Function> function = v8::Local<v8::Function>::Cast( 953 env->Global()->Get(v8::String::NewFromUtf8(env->GetIsolate(), "start"))); 954 955 int32_t duration_ms = 100; 956 v8::Handle<v8::Value> args[] = { v8::Integer::New(duration_ms) }; 957 const v8::CpuProfile* profile = 958 RunProfiler(env, function, args, ARRAY_SIZE(args), 100); 959 960 const v8::CpuProfileNode* root = profile->GetTopDownRoot(); 961 ScopedVector<v8::Handle<v8::String> > names(3); 962 names[0] = v8::String::NewFromUtf8( 963 env->GetIsolate(), ProfileGenerator::kGarbageCollectorEntryName); 964 names[1] = v8::String::NewFromUtf8(env->GetIsolate(), 965 ProfileGenerator::kProgramEntryName); 966 names[2] = v8::String::NewFromUtf8(env->GetIsolate(), "start"); 967 // Don't allow |foo| node to be at the top level. 968 CheckChildrenNames(root, names); 969 970 const v8::CpuProfileNode* startNode = 971 GetChild(env->GetIsolate(), root, "start"); 972 GetChild(env->GetIsolate(), startNode, "foo"); 973 974 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler(); 975 cpu_profiler->DeleteAllCpuProfiles(); 976 } 977 978 979 static const char* call_function_test_source = "function bar(iterations) {\n" 980 "}\n" 981 "function start(duration) {\n" 982 " var start = Date.now();\n" 983 " while (Date.now() - start < duration) {\n" 984 " try {\n" 985 " bar.call(this, 10 * 1000);\n" 986 " } catch(e) {}\n" 987 " }\n" 988 "}"; 989 990 991 // Test that if we sampled thread when it was inside FunctionCall buitin then 992 // its caller frame will be '(unresolved function)' as we have no reliable way 993 // to resolve it. 994 // 995 // [Top down]: 996 // 96 0 (root) [-1] #1 997 // 1 1 (garbage collector) [-1] #4 998 // 5 0 (unresolved function) [-1] #5 999 // 5 5 call [-1] #6 1000 // 71 70 start [-1] #3 1001 // 1 1 bar [-1] #7 1002 // 19 19 (program) [-1] #2 1003 TEST(FunctionCallSample) { 1004 LocalContext env; 1005 v8::HandleScope scope(env->GetIsolate()); 1006 1007 // Collect garbage that might have be generated while installing extensions. 1008 CcTest::heap()->CollectAllGarbage(Heap::kNoGCFlags); 1009 1010 v8::Script::Compile(v8::String::NewFromUtf8( 1011 env->GetIsolate(), call_function_test_source))->Run(); 1012 v8::Local<v8::Function> function = v8::Local<v8::Function>::Cast( 1013 env->Global()->Get(v8::String::NewFromUtf8(env->GetIsolate(), "start"))); 1014 1015 int32_t duration_ms = 100; 1016 v8::Handle<v8::Value> args[] = { v8::Integer::New(duration_ms) }; 1017 const v8::CpuProfile* profile = 1018 RunProfiler(env, function, args, ARRAY_SIZE(args), 100); 1019 1020 const v8::CpuProfileNode* root = profile->GetTopDownRoot(); 1021 { 1022 ScopedVector<v8::Handle<v8::String> > names(4); 1023 names[0] = v8::String::NewFromUtf8( 1024 env->GetIsolate(), ProfileGenerator::kGarbageCollectorEntryName); 1025 names[1] = v8::String::NewFromUtf8(env->GetIsolate(), 1026 ProfileGenerator::kProgramEntryName); 1027 names[2] = v8::String::NewFromUtf8(env->GetIsolate(), "start"); 1028 names[3] = v8::String::NewFromUtf8( 1029 env->GetIsolate(), i::ProfileGenerator::kUnresolvedFunctionName); 1030 // Don't allow |bar| and |call| nodes to be at the top level. 1031 CheckChildrenNames(root, names); 1032 } 1033 1034 // In case of GC stress tests all samples may be in GC phase and there 1035 // won't be |start| node in the profiles. 1036 bool is_gc_stress_testing = 1037 (i::FLAG_gc_interval != -1) || i::FLAG_stress_compaction; 1038 const v8::CpuProfileNode* startNode = 1039 FindChild(env->GetIsolate(), root, "start"); 1040 CHECK(is_gc_stress_testing || startNode); 1041 if (startNode) { 1042 ScopedVector<v8::Handle<v8::String> > names(2); 1043 names[0] = v8::String::NewFromUtf8(env->GetIsolate(), "bar"); 1044 names[1] = v8::String::NewFromUtf8(env->GetIsolate(), "call"); 1045 CheckChildrenNames(startNode, names); 1046 } 1047 1048 const v8::CpuProfileNode* unresolvedNode = FindChild( 1049 env->GetIsolate(), root, i::ProfileGenerator::kUnresolvedFunctionName); 1050 if (unresolvedNode) { 1051 ScopedVector<v8::Handle<v8::String> > names(1); 1052 names[0] = v8::String::NewFromUtf8(env->GetIsolate(), "call"); 1053 CheckChildrenNames(unresolvedNode, names); 1054 } 1055 1056 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler(); 1057 cpu_profiler->DeleteAllCpuProfiles(); 1058 } 1059 1060 1061 static const char* function_apply_test_source = "function bar(iterations) {\n" 1062 "}\n" 1063 "function test() {\n" 1064 " bar.apply(this, [10 * 1000]);\n" 1065 "}\n" 1066 "function start(duration) {\n" 1067 " var start = Date.now();\n" 1068 " while (Date.now() - start < duration) {\n" 1069 " try {\n" 1070 " test();\n" 1071 " } catch(e) {}\n" 1072 " }\n" 1073 "}"; 1074 1075 1076 // [Top down]: 1077 // 94 0 (root) [-1] #0 1 1078 // 2 2 (garbage collector) [-1] #0 7 1079 // 82 49 start [-1] #16 3 1080 // 1 0 (unresolved function) [-1] #0 8 1081 // 1 1 apply [-1] #0 9 1082 // 32 21 test [-1] #16 4 1083 // 2 2 bar [-1] #16 6 1084 // 9 9 apply [-1] #0 5 1085 // 10 10 (program) [-1] #0 2 1086 TEST(FunctionApplySample) { 1087 LocalContext env; 1088 v8::HandleScope scope(env->GetIsolate()); 1089 1090 v8::Script::Compile( 1091 v8::String::NewFromUtf8(env->GetIsolate(), function_apply_test_source)) 1092 ->Run(); 1093 v8::Local<v8::Function> function = v8::Local<v8::Function>::Cast( 1094 env->Global()->Get(v8::String::NewFromUtf8(env->GetIsolate(), "start"))); 1095 1096 int32_t duration_ms = 100; 1097 v8::Handle<v8::Value> args[] = { v8::Integer::New(duration_ms) }; 1098 1099 const v8::CpuProfile* profile = 1100 RunProfiler(env, function, args, ARRAY_SIZE(args), 100); 1101 1102 const v8::CpuProfileNode* root = profile->GetTopDownRoot(); 1103 { 1104 ScopedVector<v8::Handle<v8::String> > names(3); 1105 names[0] = v8::String::NewFromUtf8( 1106 env->GetIsolate(), ProfileGenerator::kGarbageCollectorEntryName); 1107 names[1] = v8::String::NewFromUtf8(env->GetIsolate(), 1108 ProfileGenerator::kProgramEntryName); 1109 names[2] = v8::String::NewFromUtf8(env->GetIsolate(), "start"); 1110 // Don't allow |test|, |bar| and |apply| nodes to be at the top level. 1111 CheckChildrenNames(root, names); 1112 } 1113 1114 const v8::CpuProfileNode* startNode = 1115 FindChild(env->GetIsolate(), root, "start"); 1116 if (startNode) { 1117 { 1118 ScopedVector<v8::Handle<v8::String> > names(2); 1119 names[0] = v8::String::NewFromUtf8(env->GetIsolate(), "test"); 1120 names[1] = v8::String::NewFromUtf8( 1121 env->GetIsolate(), ProfileGenerator::kUnresolvedFunctionName); 1122 CheckChildrenNames(startNode, names); 1123 } 1124 1125 const v8::CpuProfileNode* testNode = 1126 FindChild(env->GetIsolate(), startNode, "test"); 1127 if (testNode) { 1128 ScopedVector<v8::Handle<v8::String> > names(2); 1129 names[0] = v8::String::NewFromUtf8(env->GetIsolate(), "bar"); 1130 names[1] = v8::String::NewFromUtf8(env->GetIsolate(), "apply"); 1131 CheckChildrenNames(testNode, names); 1132 } 1133 1134 if (const v8::CpuProfileNode* unresolvedNode = 1135 FindChild(env->GetIsolate(), startNode, 1136 ProfileGenerator::kUnresolvedFunctionName)) { 1137 ScopedVector<v8::Handle<v8::String> > names(1); 1138 names[0] = v8::String::NewFromUtf8(env->GetIsolate(), "apply"); 1139 CheckChildrenNames(unresolvedNode, names); 1140 GetChild(env->GetIsolate(), unresolvedNode, "apply"); 1141 } 1142 } 1143 1144 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler(); 1145 cpu_profiler->DeleteAllCpuProfiles(); 1146 } 1147 1148 1149 static const char* js_native_js_test_source = 1150 "var is_profiling = false;\n" 1151 "function foo(iterations) {\n" 1152 " if (!is_profiling) {\n" 1153 " is_profiling = true;\n" 1154 " startProfiling('my_profile');\n" 1155 " }\n" 1156 " var r = 0;\n" 1157 " for (var i = 0; i < iterations; i++) { r += i; }\n" 1158 " return r;\n" 1159 "}\n" 1160 "function bar(iterations) {\n" 1161 " try { foo(iterations); } catch(e) {}\n" 1162 "}\n" 1163 "function start(duration) {\n" 1164 " var start = Date.now();\n" 1165 " while (Date.now() - start < duration) {\n" 1166 " try {\n" 1167 " CallJsFunction(bar, 10 * 1000);\n" 1168 " } catch(e) {}\n" 1169 " }\n" 1170 "}"; 1171 1172 static void CallJsFunction(const v8::FunctionCallbackInfo<v8::Value>& info) { 1173 v8::Handle<v8::Function> function = info[0].As<v8::Function>(); 1174 v8::Handle<v8::Value> argv[] = { info[1] }; 1175 function->Call(info.This(), ARRAY_SIZE(argv), argv); 1176 } 1177 1178 1179 // [Top down]: 1180 // 58 0 (root) #0 1 1181 // 2 2 (program) #0 2 1182 // 56 1 start #16 3 1183 // 55 0 CallJsFunction #0 4 1184 // 55 1 bar #16 5 1185 // 54 54 foo #16 6 1186 TEST(JsNativeJsSample) { 1187 const char* extensions[] = { "v8/profiler" }; 1188 v8::ExtensionConfiguration config(1, extensions); 1189 LocalContext env(&config); 1190 v8::HandleScope scope(env->GetIsolate()); 1191 1192 v8::Local<v8::FunctionTemplate> func_template = v8::FunctionTemplate::New( 1193 CallJsFunction); 1194 v8::Local<v8::Function> func = func_template->GetFunction(); 1195 func->SetName(v8::String::NewFromUtf8(env->GetIsolate(), "CallJsFunction")); 1196 env->Global()->Set( 1197 v8::String::NewFromUtf8(env->GetIsolate(), "CallJsFunction"), func); 1198 1199 v8::Script::Compile(v8::String::NewFromUtf8(env->GetIsolate(), 1200 js_native_js_test_source))->Run(); 1201 v8::Local<v8::Function> function = v8::Local<v8::Function>::Cast( 1202 env->Global()->Get(v8::String::NewFromUtf8(env->GetIsolate(), "start"))); 1203 1204 int32_t duration_ms = 20; 1205 v8::Handle<v8::Value> args[] = { v8::Integer::New(duration_ms) }; 1206 const v8::CpuProfile* profile = 1207 RunProfiler(env, function, args, ARRAY_SIZE(args), 10); 1208 1209 const v8::CpuProfileNode* root = profile->GetTopDownRoot(); 1210 { 1211 ScopedVector<v8::Handle<v8::String> > names(3); 1212 names[0] = v8::String::NewFromUtf8( 1213 env->GetIsolate(), ProfileGenerator::kGarbageCollectorEntryName); 1214 names[1] = v8::String::NewFromUtf8(env->GetIsolate(), 1215 ProfileGenerator::kProgramEntryName); 1216 names[2] = v8::String::NewFromUtf8(env->GetIsolate(), "start"); 1217 CheckChildrenNames(root, names); 1218 } 1219 1220 const v8::CpuProfileNode* startNode = 1221 GetChild(env->GetIsolate(), root, "start"); 1222 CHECK_EQ(1, startNode->GetChildrenCount()); 1223 const v8::CpuProfileNode* nativeFunctionNode = 1224 GetChild(env->GetIsolate(), startNode, "CallJsFunction"); 1225 1226 CHECK_EQ(1, nativeFunctionNode->GetChildrenCount()); 1227 const v8::CpuProfileNode* barNode = 1228 GetChild(env->GetIsolate(), nativeFunctionNode, "bar"); 1229 1230 CHECK_EQ(1, barNode->GetChildrenCount()); 1231 GetChild(env->GetIsolate(), barNode, "foo"); 1232 1233 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler(); 1234 cpu_profiler->DeleteAllCpuProfiles(); 1235 } 1236 1237 1238 static const char* js_native_js_runtime_js_test_source = 1239 "var is_profiling = false;\n" 1240 "function foo(iterations) {\n" 1241 " if (!is_profiling) {\n" 1242 " is_profiling = true;\n" 1243 " startProfiling('my_profile');\n" 1244 " }\n" 1245 " var r = 0;\n" 1246 " for (var i = 0; i < iterations; i++) { r += i; }\n" 1247 " return r;\n" 1248 "}\n" 1249 "var bound = foo.bind(this);\n" 1250 "function bar(iterations) {\n" 1251 " try { bound(iterations); } catch(e) {}\n" 1252 "}\n" 1253 "function start(duration) {\n" 1254 " var start = Date.now();\n" 1255 " while (Date.now() - start < duration) {\n" 1256 " try {\n" 1257 " CallJsFunction(bar, 10 * 1000);\n" 1258 " } catch(e) {}\n" 1259 " }\n" 1260 "}"; 1261 1262 1263 // [Top down]: 1264 // 57 0 (root) #0 1 1265 // 55 1 start #16 3 1266 // 54 0 CallJsFunction #0 4 1267 // 54 3 bar #16 5 1268 // 51 51 foo #16 6 1269 // 2 2 (program) #0 2 1270 TEST(JsNativeJsRuntimeJsSample) { 1271 const char* extensions[] = { "v8/profiler" }; 1272 v8::ExtensionConfiguration config(1, extensions); 1273 LocalContext env(&config); 1274 v8::HandleScope scope(env->GetIsolate()); 1275 1276 v8::Local<v8::FunctionTemplate> func_template = v8::FunctionTemplate::New( 1277 CallJsFunction); 1278 v8::Local<v8::Function> func = func_template->GetFunction(); 1279 func->SetName(v8::String::NewFromUtf8(env->GetIsolate(), "CallJsFunction")); 1280 env->Global()->Set( 1281 v8::String::NewFromUtf8(env->GetIsolate(), "CallJsFunction"), func); 1282 1283 v8::Script::Compile( 1284 v8::String::NewFromUtf8(env->GetIsolate(), 1285 js_native_js_runtime_js_test_source))->Run(); 1286 v8::Local<v8::Function> function = v8::Local<v8::Function>::Cast( 1287 env->Global()->Get(v8::String::NewFromUtf8(env->GetIsolate(), "start"))); 1288 1289 int32_t duration_ms = 20; 1290 v8::Handle<v8::Value> args[] = { v8::Integer::New(duration_ms) }; 1291 const v8::CpuProfile* profile = 1292 RunProfiler(env, function, args, ARRAY_SIZE(args), 10); 1293 1294 const v8::CpuProfileNode* root = profile->GetTopDownRoot(); 1295 ScopedVector<v8::Handle<v8::String> > names(3); 1296 names[0] = v8::String::NewFromUtf8( 1297 env->GetIsolate(), ProfileGenerator::kGarbageCollectorEntryName); 1298 names[1] = v8::String::NewFromUtf8(env->GetIsolate(), 1299 ProfileGenerator::kProgramEntryName); 1300 names[2] = v8::String::NewFromUtf8(env->GetIsolate(), "start"); 1301 CheckChildrenNames(root, names); 1302 1303 const v8::CpuProfileNode* startNode = 1304 GetChild(env->GetIsolate(), root, "start"); 1305 CHECK_EQ(1, startNode->GetChildrenCount()); 1306 const v8::CpuProfileNode* nativeFunctionNode = 1307 GetChild(env->GetIsolate(), startNode, "CallJsFunction"); 1308 1309 CHECK_EQ(1, nativeFunctionNode->GetChildrenCount()); 1310 const v8::CpuProfileNode* barNode = 1311 GetChild(env->GetIsolate(), nativeFunctionNode, "bar"); 1312 1313 CHECK_EQ(1, barNode->GetChildrenCount()); 1314 GetChild(env->GetIsolate(), barNode, "foo"); 1315 1316 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler(); 1317 cpu_profiler->DeleteAllCpuProfiles(); 1318 } 1319 1320 1321 static void CallJsFunction2(const v8::FunctionCallbackInfo<v8::Value>& info) { 1322 CallJsFunction(info); 1323 } 1324 1325 1326 static const char* js_native1_js_native2_js_test_source = 1327 "var is_profiling = false;\n" 1328 "function foo(iterations) {\n" 1329 " if (!is_profiling) {\n" 1330 " is_profiling = true;\n" 1331 " startProfiling('my_profile');\n" 1332 " }\n" 1333 " var r = 0;\n" 1334 " for (var i = 0; i < iterations; i++) { r += i; }\n" 1335 " return r;\n" 1336 "}\n" 1337 "function bar(iterations) {\n" 1338 " CallJsFunction2(foo, iterations);\n" 1339 "}\n" 1340 "function start(duration) {\n" 1341 " var start = Date.now();\n" 1342 " while (Date.now() - start < duration) {\n" 1343 " try {\n" 1344 " CallJsFunction1(bar, 10 * 1000);\n" 1345 " } catch(e) {}\n" 1346 " }\n" 1347 "}"; 1348 1349 1350 // [Top down]: 1351 // 57 0 (root) #0 1 1352 // 55 1 start #16 3 1353 // 54 0 CallJsFunction1 #0 4 1354 // 54 0 bar #16 5 1355 // 54 0 CallJsFunction2 #0 6 1356 // 54 54 foo #16 7 1357 // 2 2 (program) #0 2 1358 TEST(JsNative1JsNative2JsSample) { 1359 const char* extensions[] = { "v8/profiler" }; 1360 v8::ExtensionConfiguration config(1, extensions); 1361 LocalContext env(&config); 1362 v8::HandleScope scope(env->GetIsolate()); 1363 1364 v8::Local<v8::FunctionTemplate> func_template = v8::FunctionTemplate::New( 1365 CallJsFunction); 1366 v8::Local<v8::Function> func1 = func_template->GetFunction(); 1367 func1->SetName(v8::String::NewFromUtf8(env->GetIsolate(), "CallJsFunction1")); 1368 env->Global()->Set( 1369 v8::String::NewFromUtf8(env->GetIsolate(), "CallJsFunction1"), func1); 1370 1371 v8::Local<v8::Function> func2 = v8::FunctionTemplate::New( 1372 CallJsFunction2)->GetFunction(); 1373 func2->SetName(v8::String::NewFromUtf8(env->GetIsolate(), "CallJsFunction2")); 1374 env->Global()->Set( 1375 v8::String::NewFromUtf8(env->GetIsolate(), "CallJsFunction2"), func2); 1376 1377 v8::Script::Compile( 1378 v8::String::NewFromUtf8(env->GetIsolate(), 1379 js_native1_js_native2_js_test_source))->Run(); 1380 v8::Local<v8::Function> function = v8::Local<v8::Function>::Cast( 1381 env->Global()->Get(v8::String::NewFromUtf8(env->GetIsolate(), "start"))); 1382 1383 int32_t duration_ms = 20; 1384 v8::Handle<v8::Value> args[] = { v8::Integer::New(duration_ms) }; 1385 const v8::CpuProfile* profile = 1386 RunProfiler(env, function, args, ARRAY_SIZE(args), 10); 1387 1388 const v8::CpuProfileNode* root = profile->GetTopDownRoot(); 1389 ScopedVector<v8::Handle<v8::String> > names(3); 1390 names[0] = v8::String::NewFromUtf8( 1391 env->GetIsolate(), ProfileGenerator::kGarbageCollectorEntryName); 1392 names[1] = v8::String::NewFromUtf8(env->GetIsolate(), 1393 ProfileGenerator::kProgramEntryName); 1394 names[2] = v8::String::NewFromUtf8(env->GetIsolate(), "start"); 1395 CheckChildrenNames(root, names); 1396 1397 const v8::CpuProfileNode* startNode = 1398 GetChild(env->GetIsolate(), root, "start"); 1399 CHECK_EQ(1, startNode->GetChildrenCount()); 1400 const v8::CpuProfileNode* nativeNode1 = 1401 GetChild(env->GetIsolate(), startNode, "CallJsFunction1"); 1402 1403 CHECK_EQ(1, nativeNode1->GetChildrenCount()); 1404 const v8::CpuProfileNode* barNode = 1405 GetChild(env->GetIsolate(), nativeNode1, "bar"); 1406 1407 CHECK_EQ(1, barNode->GetChildrenCount()); 1408 const v8::CpuProfileNode* nativeNode2 = 1409 GetChild(env->GetIsolate(), barNode, "CallJsFunction2"); 1410 1411 CHECK_EQ(1, nativeNode2->GetChildrenCount()); 1412 GetChild(env->GetIsolate(), nativeNode2, "foo"); 1413 1414 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler(); 1415 cpu_profiler->DeleteAllCpuProfiles(); 1416 } 1417 1418 1419 // [Top down]: 1420 // 6 0 (root) #0 1 1421 // 3 3 (program) #0 2 1422 // 3 3 (idle) #0 3 1423 TEST(IdleTime) { 1424 LocalContext env; 1425 v8::HandleScope scope(env->GetIsolate()); 1426 v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler(); 1427 1428 v8::Local<v8::String> profile_name = 1429 v8::String::NewFromUtf8(env->GetIsolate(), "my_profile"); 1430 cpu_profiler->StartCpuProfiling(profile_name); 1431 1432 i::Isolate* isolate = CcTest::i_isolate(); 1433 i::ProfilerEventsProcessor* processor = isolate->cpu_profiler()->processor(); 1434 processor->AddCurrentStack(isolate); 1435 1436 cpu_profiler->SetIdle(true); 1437 1438 for (int i = 0; i < 3; i++) { 1439 processor->AddCurrentStack(isolate); 1440 } 1441 1442 cpu_profiler->SetIdle(false); 1443 processor->AddCurrentStack(isolate); 1444 1445 1446 const v8::CpuProfile* profile = cpu_profiler->StopCpuProfiling(profile_name); 1447 CHECK_NE(NULL, profile); 1448 // Dump collected profile to have a better diagnostic in case of failure. 1449 reinterpret_cast<i::CpuProfile*>( 1450 const_cast<v8::CpuProfile*>(profile))->Print(); 1451 1452 const v8::CpuProfileNode* root = profile->GetTopDownRoot(); 1453 ScopedVector<v8::Handle<v8::String> > names(3); 1454 names[0] = v8::String::NewFromUtf8( 1455 env->GetIsolate(), ProfileGenerator::kGarbageCollectorEntryName); 1456 names[1] = v8::String::NewFromUtf8(env->GetIsolate(), 1457 ProfileGenerator::kProgramEntryName); 1458 names[2] = v8::String::NewFromUtf8(env->GetIsolate(), 1459 ProfileGenerator::kIdleEntryName); 1460 CheckChildrenNames(root, names); 1461 1462 const v8::CpuProfileNode* programNode = 1463 GetChild(env->GetIsolate(), root, ProfileGenerator::kProgramEntryName); 1464 CHECK_EQ(0, programNode->GetChildrenCount()); 1465 CHECK_GE(programNode->GetHitCount(), 3); 1466 1467 const v8::CpuProfileNode* idleNode = 1468 GetChild(env->GetIsolate(), root, ProfileGenerator::kIdleEntryName); 1469 CHECK_EQ(0, idleNode->GetChildrenCount()); 1470 CHECK_GE(idleNode->GetHitCount(), 3); 1471 1472 cpu_profiler->DeleteAllCpuProfiles(); 1473 } 1474 1475 1476 static void CheckFunctionDetails(v8::Isolate* isolate, 1477 const v8::CpuProfileNode* node, 1478 const char* name, const char* script_name, 1479 int script_id, int line, int column) { 1480 CHECK_EQ(v8::String::NewFromUtf8(isolate, name), 1481 node->GetFunctionName()); 1482 CHECK_EQ(v8::String::NewFromUtf8(isolate, script_name), 1483 node->GetScriptResourceName()); 1484 CHECK_EQ(script_id, node->GetScriptId()); 1485 CHECK_EQ(line, node->GetLineNumber()); 1486 CHECK_EQ(column, node->GetColumnNumber()); 1487 } 1488 1489 1490 TEST(FunctionDetails) { 1491 const char* extensions[] = { "v8/profiler" }; 1492 v8::ExtensionConfiguration config(1, extensions); 1493 LocalContext env(&config); 1494 v8::HandleScope handleScope(env->GetIsolate()); 1495 1496 v8::CpuProfiler* profiler = env->GetIsolate()->GetCpuProfiler(); 1497 CHECK_EQ(0, profiler->GetProfileCount()); 1498 v8::Handle<v8::Script> script_a = v8::Script::Compile( 1499 v8::String::NewFromUtf8( 1500 env->GetIsolate(), 1501 " function foo\n() { try { bar(); } catch(e) {} }\n" 1502 " function bar() { startProfiling(); }\n"), 1503 v8::String::NewFromUtf8(env->GetIsolate(), "script_a")); 1504 script_a->Run(); 1505 v8::Handle<v8::Script> script_b = v8::Script::Compile( 1506 v8::String::NewFromUtf8( 1507 env->GetIsolate(), 1508 "\n\n function baz() { try { foo(); } catch(e) {} }\n" 1509 "\n\nbaz();\n" 1510 "stopProfiling();\n"), 1511 v8::String::NewFromUtf8(env->GetIsolate(), "script_b")); 1512 script_b->Run(); 1513 CHECK_EQ(1, profiler->GetProfileCount()); 1514 const v8::CpuProfile* profile = profiler->GetCpuProfile(0); 1515 const v8::CpuProfileNode* current = profile->GetTopDownRoot(); 1516 reinterpret_cast<ProfileNode*>( 1517 const_cast<v8::CpuProfileNode*>(current))->Print(0); 1518 // The tree should look like this: 1519 // 0 (root) 0 #1 1520 // 0 (anonymous function) 19 #2 no reason script_b:1 1521 // 0 baz 19 #3 TryCatchStatement script_b:3 1522 // 0 foo 18 #4 TryCatchStatement script_a:2 1523 // 1 bar 18 #5 no reason script_a:3 1524 const v8::CpuProfileNode* root = profile->GetTopDownRoot(); 1525 const v8::CpuProfileNode* script = GetChild(env->GetIsolate(), root, 1526 ProfileGenerator::kAnonymousFunctionName); 1527 CheckFunctionDetails(env->GetIsolate(), script, 1528 ProfileGenerator::kAnonymousFunctionName, "script_b", 1529 script_b->GetId(), 1, 1); 1530 const v8::CpuProfileNode* baz = GetChild(env->GetIsolate(), script, "baz"); 1531 CheckFunctionDetails(env->GetIsolate(), baz, "baz", "script_b", 1532 script_b->GetId(), 3, 16); 1533 const v8::CpuProfileNode* foo = GetChild(env->GetIsolate(), baz, "foo"); 1534 CheckFunctionDetails(env->GetIsolate(), foo, "foo", "script_a", 1535 script_a->GetId(), 2, 1); 1536 const v8::CpuProfileNode* bar = GetChild(env->GetIsolate(), foo, "bar"); 1537 CheckFunctionDetails(env->GetIsolate(), bar, "bar", "script_a", 1538 script_a->GetId(), 3, 14); 1539 } 1540
