Chromium Code Reviews| 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 121 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
| 132 v8::Script::Compile(v8::String::New(src))->Run(); | 132 v8::Script::Compile(v8::String::New(src))->Run(); |
| 133 } | 133 } |
| 134 | 134 |
| 135 | 135 |
| 136 namespace v8 { | 136 namespace v8 { |
| 137 namespace internal { | 137 namespace internal { |
| 138 | 138 |
| 139 class LoggerTestHelper : public AllStatic { | 139 class LoggerTestHelper : public AllStatic { |
| 140 public: | 140 public: |
| 141 static bool IsSamplerActive() { return Logger::IsProfilerSamplerActive(); } | 141 static bool IsSamplerActive() { return Logger::IsProfilerSamplerActive(); } |
| 142 static void reset_samples_taken() { | |
| 143 reinterpret_cast<Sampler*>(Logger::ticker_)->reset_samples_taken(); | |
| 144 } | |
| 145 static bool has_samples_taken() { | |
| 146 return reinterpret_cast<Sampler*>(Logger::ticker_)->samples_taken() > 0; | |
| 147 } | |
| 142 }; | 148 }; |
| 143 | 149 |
| 144 } // namespace v8::internal | 150 } // namespace v8::internal |
| 145 } // namespace v8 | 151 } // namespace v8 |
| 146 | 152 |
| 147 using v8::internal::LoggerTestHelper; | 153 using v8::internal::LoggerTestHelper; |
| 148 | 154 |
| 149 | 155 |
| 150 // Under Linux, we need to check if signals were delivered to avoid false | |
| 151 // positives. Under other platforms profiling is done via a high-priority | |
| 152 // thread, so this case never happen. | |
| 153 static bool was_sigprof_received = true; | |
| 154 #ifdef __linux__ | |
| 155 | |
| 156 struct sigaction old_sigprof_handler; | |
| 157 pthread_t our_thread; | |
| 158 | |
| 159 static void SigProfSignalHandler(int signal, siginfo_t* info, void* context) { | |
| 160 if (signal != SIGPROF || !pthread_equal(pthread_self(), our_thread)) return; | |
| 161 was_sigprof_received = true; | |
| 162 old_sigprof_handler.sa_sigaction(signal, info, context); | |
| 163 } | |
| 164 | |
| 165 #endif // __linux__ | |
| 166 | |
| 167 | |
| 168 namespace { | 156 namespace { |
| 169 | 157 |
| 170 class ScopedLoggerInitializer { | 158 class ScopedLoggerInitializer { |
| 171 public: | 159 public: |
| 172 explicit ScopedLoggerInitializer(bool prof_lazy) | 160 explicit ScopedLoggerInitializer(bool prof_lazy) |
| 173 : saved_prof_lazy_(i::FLAG_prof_lazy), | 161 : saved_prof_lazy_(i::FLAG_prof_lazy), |
| 174 saved_prof_(i::FLAG_prof), | 162 saved_prof_(i::FLAG_prof), |
| 175 saved_prof_auto_(i::FLAG_prof_auto), | 163 saved_prof_auto_(i::FLAG_prof_auto), |
| 176 trick_to_run_init_flags_(init_flags_(prof_lazy)), | 164 trick_to_run_init_flags_(init_flags_(prof_lazy)), |
| 177 need_to_set_up_logger_(i::V8::IsRunning()), | 165 need_to_set_up_logger_(i::V8::IsRunning()), |
| (...skipping 81 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
| 259 | 247 |
| 260 static void CheckThatProfilerWorks(LogBufferMatcher* matcher) { | 248 static void CheckThatProfilerWorks(LogBufferMatcher* matcher) { |
| 261 Logger::ResumeProfiler(v8::PROFILER_MODULE_CPU, 0); | 249 Logger::ResumeProfiler(v8::PROFILER_MODULE_CPU, 0); |
| 262 CHECK(LoggerTestHelper::IsSamplerActive()); | 250 CHECK(LoggerTestHelper::IsSamplerActive()); |
| 263 | 251 |
| 264 // Verify that the current map of compiled functions has been logged. | 252 // Verify that the current map of compiled functions has been logged. |
| 265 CHECK_GT(matcher->GetNextChunk(), 0); | 253 CHECK_GT(matcher->GetNextChunk(), 0); |
| 266 const char* code_creation = "\ncode-creation,"; // eq. to /^code-creation,/ | 254 const char* code_creation = "\ncode-creation,"; // eq. to /^code-creation,/ |
| 267 CHECK_NE(NULL, matcher->Find(code_creation)); | 255 CHECK_NE(NULL, matcher->Find(code_creation)); |
| 268 | 256 |
| 269 #ifdef __linux__ | 257 LoggerTestHelper::reset_samples_taken(); |
|
Vitaly Repeshko
2010/11/25 15:01:20
Should be done while the profiler is paused.
mnaganov (inactive)
2010/11/25 15:26:56
Done.
| |
| 270 // Intercept SIGPROF handler to make sure that the test process | |
| 271 // had received it. Under load, system can defer it causing test failure. | |
| 272 // It is important to execute this after 'ResumeProfiler'. | |
| 273 our_thread = pthread_self(); | |
| 274 was_sigprof_received = false; | |
| 275 struct sigaction sa; | |
| 276 sa.sa_sigaction = SigProfSignalHandler; | |
| 277 sigemptyset(&sa.sa_mask); | |
| 278 sa.sa_flags = SA_SIGINFO; | |
| 279 CHECK_EQ(0, sigaction(SIGPROF, &sa, &old_sigprof_handler)); | |
| 280 #endif // __linux__ | |
| 281 | 258 |
| 282 // Force compiler to generate new code by parametrizing source. | 259 // Force compiler to generate new code by parametrizing source. |
| 283 EmbeddedVector<char, 100> script_src; | 260 EmbeddedVector<char, 100> script_src; |
| 284 i::OS::SNPrintF(script_src, | 261 i::OS::SNPrintF(script_src, |
| 285 "function f%d(x) { return %d * x; }" | 262 "function f%d(x) { return %d * x; }" |
| 286 "for (var i = 0; i < 10000; ++i) { f%d(i); }", | 263 "for (var i = 0; i < 10000; ++i) { f%d(i); }", |
| 287 matcher->log_pos(), matcher->log_pos(), matcher->log_pos()); | 264 matcher->log_pos(), matcher->log_pos(), matcher->log_pos()); |
| 288 // Run code for 200 msecs to get some ticks. | 265 // Run code for 200 msecs to get some ticks. |
| 289 const double end_time = i::OS::TimeCurrentMillis() + 200; | 266 const double end_time = i::OS::TimeCurrentMillis() + 200; |
| 290 while (i::OS::TimeCurrentMillis() < end_time) { | 267 while (i::OS::TimeCurrentMillis() < end_time) { |
| 291 CompileAndRunScript(script_src.start()); | 268 CompileAndRunScript(script_src.start()); |
| 292 // Yield CPU to give Profiler thread a chance to process ticks. | 269 // Yield CPU to give Profiler thread a chance to process ticks. |
| 293 i::OS::Sleep(1); | 270 i::OS::Sleep(1); |
| 294 } | 271 } |
| 295 | 272 |
| 296 Logger::PauseProfiler(v8::PROFILER_MODULE_CPU, 0); | 273 Logger::PauseProfiler(v8::PROFILER_MODULE_CPU, 0); |
| 297 CHECK(!LoggerTestHelper::IsSamplerActive()); | 274 CHECK(!LoggerTestHelper::IsSamplerActive()); |
| 298 | 275 |
| 299 // Wait 50 msecs to allow Profiler thread to process the last | 276 // Wait 50 msecs to allow Profiler thread to process the last |
| 300 // tick sample it has got. | 277 // tick sample it has got. |
| 301 i::OS::Sleep(50); | 278 i::OS::Sleep(50); |
| 302 | 279 |
| 303 // Now we must have compiler and tick records. | 280 // Now we must have compiler and tick records. |
| 304 CHECK_GT(matcher->GetNextChunk(), 0); | 281 CHECK_GT(matcher->GetNextChunk(), 0); |
| 305 matcher->PrintBuffer(); | 282 matcher->PrintBuffer(); |
| 306 CHECK_NE(NULL, matcher->Find(code_creation)); | 283 CHECK_NE(NULL, matcher->Find(code_creation)); |
| 307 const char* tick = "\ntick,"; | 284 const char* tick = "\ntick,"; |
| 308 const bool ticks_found = matcher->Find(tick) != NULL; | 285 const bool ticks_found = matcher->Find(tick) != NULL; |
| 309 CHECK_EQ(was_sigprof_received, ticks_found); | 286 CHECK_EQ(LoggerTestHelper::has_samples_taken(), ticks_found); |
| 310 } | 287 } |
| 311 | 288 |
| 312 | 289 |
| 313 TEST(ProfLazyMode) { | 290 TEST(ProfLazyMode) { |
| 314 ScopedLoggerInitializer initialize_logger(true); | 291 ScopedLoggerInitializer initialize_logger(true); |
| 315 | 292 |
| 316 // No sampling should happen prior to resuming profiler. | 293 // No sampling should happen prior to resuming profiler. |
| 317 CHECK(!LoggerTestHelper::IsSamplerActive()); | 294 CHECK(!LoggerTestHelper::IsSamplerActive()); |
| 318 | 295 |
| 319 LogBufferMatcher matcher; | 296 LogBufferMatcher matcher; |
| (...skipping 869 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
| 1189 // Make sure that all log data is written prior crash due to CHECK failure. | 1166 // Make sure that all log data is written prior crash due to CHECK failure. |
| 1190 fflush(stdout); | 1167 fflush(stdout); |
| 1191 CHECK(results_equal); | 1168 CHECK(results_equal); |
| 1192 | 1169 |
| 1193 env->Exit(); | 1170 env->Exit(); |
| 1194 Logger::TearDown(); | 1171 Logger::TearDown(); |
| 1195 i::FLAG_always_compact = saved_always_compact; | 1172 i::FLAG_always_compact = saved_always_compact; |
| 1196 } | 1173 } |
| 1197 | 1174 |
| 1198 #endif // ENABLE_LOGGING_AND_PROFILING | 1175 #endif // ENABLE_LOGGING_AND_PROFILING |
| OLD | NEW |