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 |