| OLD | NEW |
| 1 // Copyright 2006-2009 the V8 project authors. All rights reserved. | 1 // Copyright 2006-2009 the V8 project authors. All rights reserved. |
| 2 // | 2 // |
| 3 // Tests of logging functions from log.h | 3 // Tests of logging functions from log.h |
| 4 | 4 |
| 5 #ifdef ENABLE_LOGGING_AND_PROFILING | 5 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 6 | 6 |
| 7 #ifdef __linux__ | 7 #ifdef __linux__ |
| 8 #include <math.h> | 8 #include <math.h> |
| 9 #include <pthread.h> | 9 #include <pthread.h> |
| 10 #include <signal.h> | 10 #include <signal.h> |
| (...skipping 233 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 244 }; | 244 }; |
| 245 | 245 |
| 246 } // namespace | 246 } // namespace |
| 247 | 247 |
| 248 | 248 |
| 249 static void CheckThatProfilerWorks(LogBufferMatcher* matcher) { | 249 static void CheckThatProfilerWorks(LogBufferMatcher* matcher) { |
| 250 CHECK(i::RuntimeProfiler::IsEnabled() || | 250 CHECK(i::RuntimeProfiler::IsEnabled() || |
| 251 !LoggerTestHelper::IsSamplerActive()); | 251 !LoggerTestHelper::IsSamplerActive()); |
| 252 LoggerTestHelper::ResetSamplesTaken(); | 252 LoggerTestHelper::ResetSamplesTaken(); |
| 253 | 253 |
| 254 LOGGER->ResumeProfiler(v8::PROFILER_MODULE_CPU, 0); | 254 LOGGER->ResumeProfiler(); |
| 255 CHECK(LoggerTestHelper::IsSamplerActive()); | 255 CHECK(LoggerTestHelper::IsSamplerActive()); |
| 256 | 256 |
| 257 // Verify that the current map of compiled functions has been logged. | 257 // Verify that the current map of compiled functions has been logged. |
| 258 CHECK_GT(matcher->GetNextChunk(), 0); | 258 CHECK_GT(matcher->GetNextChunk(), 0); |
| 259 const char* code_creation = "\ncode-creation,"; // eq. to /^code-creation,/ | 259 const char* code_creation = "\ncode-creation,"; // eq. to /^code-creation,/ |
| 260 CHECK_NE(NULL, matcher->Find(code_creation)); | 260 CHECK_NE(NULL, matcher->Find(code_creation)); |
| 261 | 261 |
| 262 // Force compiler to generate new code by parametrizing source. | 262 // Force compiler to generate new code by parametrizing source. |
| 263 EmbeddedVector<char, 100> script_src; | 263 EmbeddedVector<char, 100> script_src; |
| 264 i::OS::SNPrintF(script_src, | 264 i::OS::SNPrintF(script_src, |
| 265 "function f%d(x) { return %d * x; }" | 265 "function f%d(x) { return %d * x; }" |
| 266 "for (var i = 0; i < 10000; ++i) { f%d(i); }", | 266 "for (var i = 0; i < 10000; ++i) { f%d(i); }", |
| 267 matcher->log_pos(), matcher->log_pos(), matcher->log_pos()); | 267 matcher->log_pos(), matcher->log_pos(), matcher->log_pos()); |
| 268 // Run code for 200 msecs to get some ticks. | 268 // Run code for 200 msecs to get some ticks. |
| 269 const double end_time = i::OS::TimeCurrentMillis() + 200; | 269 const double end_time = i::OS::TimeCurrentMillis() + 200; |
| 270 while (i::OS::TimeCurrentMillis() < end_time) { | 270 while (i::OS::TimeCurrentMillis() < end_time) { |
| 271 CompileAndRunScript(script_src.start()); | 271 CompileAndRunScript(script_src.start()); |
| 272 // Yield CPU to give Profiler thread a chance to process ticks. | 272 // Yield CPU to give Profiler thread a chance to process ticks. |
| 273 i::OS::Sleep(1); | 273 i::OS::Sleep(1); |
| 274 } | 274 } |
| 275 | 275 |
| 276 LOGGER->PauseProfiler(v8::PROFILER_MODULE_CPU, 0); | 276 LOGGER->PauseProfiler(); |
| 277 CHECK(i::RuntimeProfiler::IsEnabled() || | 277 CHECK(i::RuntimeProfiler::IsEnabled() || |
| 278 !LoggerTestHelper::IsSamplerActive()); | 278 !LoggerTestHelper::IsSamplerActive()); |
| 279 | 279 |
| 280 // Wait 50 msecs to allow Profiler thread to process the last | 280 // Wait 50 msecs to allow Profiler thread to process the last |
| 281 // tick sample it has got. | 281 // tick sample it has got. |
| 282 i::OS::Sleep(50); | 282 i::OS::Sleep(50); |
| 283 | 283 |
| 284 // Now we must have compiler and tick records. | 284 // Now we must have compiler and tick records. |
| 285 CHECK_GT(matcher->GetNextChunk(), 0); | 285 CHECK_GT(matcher->GetNextChunk(), 0); |
| 286 matcher->PrintBuffer(); | 286 matcher->PrintBuffer(); |
| (...skipping 320 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 607 EmbeddedVector<char, 100> prop2_getter_record; | 607 EmbeddedVector<char, 100> prop2_getter_record; |
| 608 i::OS::SNPrintF(prop2_getter_record, | 608 i::OS::SNPrintF(prop2_getter_record, |
| 609 "code-creation,Callback,0x%" V8PRIxPTR ",1,\"get prop2\"", | 609 "code-creation,Callback,0x%" V8PRIxPTR ",1,\"get prop2\"", |
| 610 Prop2Getter); | 610 Prop2Getter); |
| 611 CHECK_NE(NULL, matcher.Find(prop2_getter_record)); | 611 CHECK_NE(NULL, matcher.Find(prop2_getter_record)); |
| 612 | 612 |
| 613 obj.Dispose(); | 613 obj.Dispose(); |
| 614 } | 614 } |
| 615 | 615 |
| 616 | 616 |
| 617 TEST(LogTags) { | |
| 618 ScopedLoggerInitializer initialize_logger(false); | |
| 619 LogBufferMatcher matcher; | |
| 620 | |
| 621 const char* open_tag = "open-tag,"; | |
| 622 const char* close_tag = "close-tag,"; | |
| 623 | |
| 624 // Check compatibility with the old style behavior. | |
| 625 CHECK_EQ(v8::PROFILER_MODULE_NONE, LOGGER->GetActiveProfilerModules()); | |
| 626 LOGGER->ResumeProfiler(v8::PROFILER_MODULE_CPU, 0); | |
| 627 CHECK_EQ(v8::PROFILER_MODULE_CPU, LOGGER->GetActiveProfilerModules()); | |
| 628 LOGGER->PauseProfiler(v8::PROFILER_MODULE_CPU, 0); | |
| 629 CHECK_EQ(v8::PROFILER_MODULE_NONE, LOGGER->GetActiveProfilerModules()); | |
| 630 CHECK_EQ(NULL, matcher.Find(open_tag)); | |
| 631 CHECK_EQ(NULL, matcher.Find(close_tag)); | |
| 632 | |
| 633 const char* open_tag1 = "open-tag,1\n"; | |
| 634 const char* close_tag1 = "close-tag,1\n"; | |
| 635 | |
| 636 // Check non-nested tag case. | |
| 637 CHECK_EQ(v8::PROFILER_MODULE_NONE, LOGGER->GetActiveProfilerModules()); | |
| 638 LOGGER->ResumeProfiler(v8::PROFILER_MODULE_CPU, 1); | |
| 639 CHECK_EQ(v8::PROFILER_MODULE_CPU, LOGGER->GetActiveProfilerModules()); | |
| 640 LOGGER->PauseProfiler(v8::PROFILER_MODULE_CPU, 1); | |
| 641 CHECK_EQ(v8::PROFILER_MODULE_NONE, LOGGER->GetActiveProfilerModules()); | |
| 642 CHECK_GT(matcher.GetNextChunk(), 0); | |
| 643 CHECK(matcher.IsInSequence(open_tag1, close_tag1)); | |
| 644 | |
| 645 const char* open_tag2 = "open-tag,2\n"; | |
| 646 const char* close_tag2 = "close-tag,2\n"; | |
| 647 | |
| 648 // Check nested tags case. | |
| 649 CHECK_EQ(v8::PROFILER_MODULE_NONE, LOGGER->GetActiveProfilerModules()); | |
| 650 LOGGER->ResumeProfiler(v8::PROFILER_MODULE_CPU, 1); | |
| 651 CHECK_EQ(v8::PROFILER_MODULE_CPU, LOGGER->GetActiveProfilerModules()); | |
| 652 LOGGER->ResumeProfiler(v8::PROFILER_MODULE_CPU, 2); | |
| 653 CHECK_EQ(v8::PROFILER_MODULE_CPU, LOGGER->GetActiveProfilerModules()); | |
| 654 LOGGER->PauseProfiler(v8::PROFILER_MODULE_CPU, 2); | |
| 655 CHECK_EQ(v8::PROFILER_MODULE_CPU, LOGGER->GetActiveProfilerModules()); | |
| 656 LOGGER->PauseProfiler(v8::PROFILER_MODULE_CPU, 1); | |
| 657 CHECK_EQ(v8::PROFILER_MODULE_NONE, LOGGER->GetActiveProfilerModules()); | |
| 658 CHECK_GT(matcher.GetNextChunk(), 0); | |
| 659 // open_tag1 < open_tag2 < close_tag2 < close_tag1 | |
| 660 CHECK(matcher.IsInSequence(open_tag1, open_tag2)); | |
| 661 CHECK(matcher.IsInSequence(open_tag2, close_tag2)); | |
| 662 CHECK(matcher.IsInSequence(close_tag2, close_tag1)); | |
| 663 | |
| 664 // Check overlapped tags case. | |
| 665 CHECK_EQ(v8::PROFILER_MODULE_NONE, LOGGER->GetActiveProfilerModules()); | |
| 666 LOGGER->ResumeProfiler(v8::PROFILER_MODULE_CPU, 1); | |
| 667 CHECK_EQ(v8::PROFILER_MODULE_CPU, LOGGER->GetActiveProfilerModules()); | |
| 668 LOGGER->ResumeProfiler(v8::PROFILER_MODULE_CPU, 2); | |
| 669 CHECK_EQ(v8::PROFILER_MODULE_CPU, LOGGER->GetActiveProfilerModules()); | |
| 670 LOGGER->PauseProfiler(v8::PROFILER_MODULE_CPU, 1); | |
| 671 CHECK_EQ(v8::PROFILER_MODULE_CPU, LOGGER->GetActiveProfilerModules()); | |
| 672 LOGGER->PauseProfiler(v8::PROFILER_MODULE_CPU, 2); | |
| 673 CHECK_EQ(v8::PROFILER_MODULE_NONE, LOGGER->GetActiveProfilerModules()); | |
| 674 CHECK_GT(matcher.GetNextChunk(), 0); | |
| 675 // open_tag1 < open_tag2 < close_tag1 < close_tag2 | |
| 676 CHECK(matcher.IsInSequence(open_tag1, open_tag2)); | |
| 677 CHECK(matcher.IsInSequence(open_tag2, close_tag1)); | |
| 678 CHECK(matcher.IsInSequence(close_tag1, close_tag2)); | |
| 679 | |
| 680 const char* open_tag3 = "open-tag,3\n"; | |
| 681 const char* close_tag3 = "close-tag,3\n"; | |
| 682 | |
| 683 // Check pausing overflow case. | |
| 684 CHECK_EQ(v8::PROFILER_MODULE_NONE, LOGGER->GetActiveProfilerModules()); | |
| 685 LOGGER->ResumeProfiler(v8::PROFILER_MODULE_CPU, 1); | |
| 686 CHECK_EQ(v8::PROFILER_MODULE_CPU, LOGGER->GetActiveProfilerModules()); | |
| 687 LOGGER->ResumeProfiler(v8::PROFILER_MODULE_CPU, 2); | |
| 688 CHECK_EQ(v8::PROFILER_MODULE_CPU, LOGGER->GetActiveProfilerModules()); | |
| 689 LOGGER->PauseProfiler(v8::PROFILER_MODULE_CPU, 2); | |
| 690 CHECK_EQ(v8::PROFILER_MODULE_CPU, LOGGER->GetActiveProfilerModules()); | |
| 691 LOGGER->PauseProfiler(v8::PROFILER_MODULE_CPU, 1); | |
| 692 CHECK_EQ(v8::PROFILER_MODULE_NONE, LOGGER->GetActiveProfilerModules()); | |
| 693 LOGGER->PauseProfiler(v8::PROFILER_MODULE_CPU, 3); | |
| 694 CHECK_EQ(v8::PROFILER_MODULE_NONE, LOGGER->GetActiveProfilerModules()); | |
| 695 LOGGER->ResumeProfiler(v8::PROFILER_MODULE_CPU, 3); | |
| 696 CHECK_EQ(v8::PROFILER_MODULE_NONE, LOGGER->GetActiveProfilerModules()); | |
| 697 // Must be no tags, because logging must be disabled. | |
| 698 CHECK_EQ(NULL, matcher.Find(open_tag3)); | |
| 699 CHECK_EQ(NULL, matcher.Find(close_tag3)); | |
| 700 } | |
| 701 | |
| 702 | |
| 703 TEST(IsLoggingPreserved) { | 617 TEST(IsLoggingPreserved) { |
| 704 ScopedLoggerInitializer initialize_logger(false); | 618 ScopedLoggerInitializer initialize_logger(false); |
| 705 | 619 |
| 706 CHECK(LOGGER->is_logging()); | 620 CHECK(LOGGER->is_logging()); |
| 707 LOGGER->ResumeProfiler(v8::PROFILER_MODULE_CPU, 1); | 621 LOGGER->ResumeProfiler(); |
| 708 CHECK(LOGGER->is_logging()); | 622 CHECK(LOGGER->is_logging()); |
| 709 LOGGER->PauseProfiler(v8::PROFILER_MODULE_CPU, 1); | 623 LOGGER->PauseProfiler(); |
| 710 CHECK(LOGGER->is_logging()); | 624 CHECK(LOGGER->is_logging()); |
| 711 } | 625 } |
| 712 | 626 |
| 713 | 627 |
| 714 static inline bool IsStringEqualTo(const char* r, const char* s) { | 628 static inline bool IsStringEqualTo(const char* r, const char* s) { |
| 715 return strncmp(r, s, strlen(r)) == 0; | 629 return strncmp(r, s, strlen(r)) == 0; |
| 716 } | 630 } |
| 717 | 631 |
| 718 | 632 |
| 719 static bool Consume(const char* str, char** buf) { | 633 static bool Consume(const char* str, char** buf) { |
| (...skipping 450 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 1170 // Make sure that all log data is written prior crash due to CHECK failure. | 1084 // Make sure that all log data is written prior crash due to CHECK failure. |
| 1171 fflush(stdout); | 1085 fflush(stdout); |
| 1172 CHECK(results_equal); | 1086 CHECK(results_equal); |
| 1173 | 1087 |
| 1174 env->Exit(); | 1088 env->Exit(); |
| 1175 LOGGER->TearDown(); | 1089 LOGGER->TearDown(); |
| 1176 i::FLAG_always_compact = saved_always_compact; | 1090 i::FLAG_always_compact = saved_always_compact; |
| 1177 } | 1091 } |
| 1178 | 1092 |
| 1179 #endif // ENABLE_LOGGING_AND_PROFILING | 1093 #endif // ENABLE_LOGGING_AND_PROFILING |
| OLD | NEW |