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 ResetSamplesTaken() { |
| 143 reinterpret_cast<Sampler*>(Logger::ticker_)->ResetSamplesTaken(); |
| 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 73 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
251 | 239 |
252 private: | 240 private: |
253 EmbeddedVector<char, 102400> buffer_; | 241 EmbeddedVector<char, 102400> buffer_; |
254 int log_pos_; | 242 int log_pos_; |
255 }; | 243 }; |
256 | 244 |
257 } // namespace | 245 } // namespace |
258 | 246 |
259 | 247 |
260 static void CheckThatProfilerWorks(LogBufferMatcher* matcher) { | 248 static void CheckThatProfilerWorks(LogBufferMatcher* matcher) { |
| 249 CHECK(!LoggerTestHelper::IsSamplerActive()); |
| 250 LoggerTestHelper::ResetSamplesTaken(); |
| 251 |
261 Logger::ResumeProfiler(v8::PROFILER_MODULE_CPU, 0); | 252 Logger::ResumeProfiler(v8::PROFILER_MODULE_CPU, 0); |
262 CHECK(LoggerTestHelper::IsSamplerActive()); | 253 CHECK(LoggerTestHelper::IsSamplerActive()); |
263 | 254 |
264 // Verify that the current map of compiled functions has been logged. | 255 // Verify that the current map of compiled functions has been logged. |
265 CHECK_GT(matcher->GetNextChunk(), 0); | 256 CHECK_GT(matcher->GetNextChunk(), 0); |
266 const char* code_creation = "\ncode-creation,"; // eq. to /^code-creation,/ | 257 const char* code_creation = "\ncode-creation,"; // eq. to /^code-creation,/ |
267 CHECK_NE(NULL, matcher->Find(code_creation)); | 258 CHECK_NE(NULL, matcher->Find(code_creation)); |
268 | 259 |
269 #ifdef __linux__ | |
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 | |
282 // Force compiler to generate new code by parametrizing source. | 260 // Force compiler to generate new code by parametrizing source. |
283 EmbeddedVector<char, 100> script_src; | 261 EmbeddedVector<char, 100> script_src; |
284 i::OS::SNPrintF(script_src, | 262 i::OS::SNPrintF(script_src, |
285 "function f%d(x) { return %d * x; }" | 263 "function f%d(x) { return %d * x; }" |
286 "for (var i = 0; i < 10000; ++i) { f%d(i); }", | 264 "for (var i = 0; i < 10000; ++i) { f%d(i); }", |
287 matcher->log_pos(), matcher->log_pos(), matcher->log_pos()); | 265 matcher->log_pos(), matcher->log_pos(), matcher->log_pos()); |
288 // Run code for 200 msecs to get some ticks. | 266 // Run code for 200 msecs to get some ticks. |
289 const double end_time = i::OS::TimeCurrentMillis() + 200; | 267 const double end_time = i::OS::TimeCurrentMillis() + 200; |
290 while (i::OS::TimeCurrentMillis() < end_time) { | 268 while (i::OS::TimeCurrentMillis() < end_time) { |
291 CompileAndRunScript(script_src.start()); | 269 CompileAndRunScript(script_src.start()); |
292 // Yield CPU to give Profiler thread a chance to process ticks. | 270 // Yield CPU to give Profiler thread a chance to process ticks. |
293 i::OS::Sleep(1); | 271 i::OS::Sleep(1); |
294 } | 272 } |
295 | 273 |
296 Logger::PauseProfiler(v8::PROFILER_MODULE_CPU, 0); | 274 Logger::PauseProfiler(v8::PROFILER_MODULE_CPU, 0); |
297 CHECK(!LoggerTestHelper::IsSamplerActive()); | 275 CHECK(!LoggerTestHelper::IsSamplerActive()); |
298 | 276 |
299 // Wait 50 msecs to allow Profiler thread to process the last | 277 // Wait 50 msecs to allow Profiler thread to process the last |
300 // tick sample it has got. | 278 // tick sample it has got. |
301 i::OS::Sleep(50); | 279 i::OS::Sleep(50); |
302 | 280 |
303 // Now we must have compiler and tick records. | 281 // Now we must have compiler and tick records. |
304 CHECK_GT(matcher->GetNextChunk(), 0); | 282 CHECK_GT(matcher->GetNextChunk(), 0); |
305 matcher->PrintBuffer(); | 283 matcher->PrintBuffer(); |
306 CHECK_NE(NULL, matcher->Find(code_creation)); | 284 CHECK_NE(NULL, matcher->Find(code_creation)); |
307 const char* tick = "\ntick,"; | 285 const char* tick = "\ntick,"; |
308 const bool ticks_found = matcher->Find(tick) != NULL; | 286 const bool ticks_found = matcher->Find(tick) != NULL; |
309 CHECK_EQ(was_sigprof_received, ticks_found); | 287 CHECK_EQ(LoggerTestHelper::has_samples_taken(), ticks_found); |
310 } | 288 } |
311 | 289 |
312 | 290 |
313 TEST(ProfLazyMode) { | 291 TEST(ProfLazyMode) { |
314 ScopedLoggerInitializer initialize_logger(true); | 292 ScopedLoggerInitializer initialize_logger(true); |
315 | 293 |
316 // No sampling should happen prior to resuming profiler. | 294 // No sampling should happen prior to resuming profiler. |
317 CHECK(!LoggerTestHelper::IsSamplerActive()); | 295 CHECK(!LoggerTestHelper::IsSamplerActive()); |
318 | 296 |
319 LogBufferMatcher matcher; | 297 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. | 1167 // Make sure that all log data is written prior crash due to CHECK failure. |
1190 fflush(stdout); | 1168 fflush(stdout); |
1191 CHECK(results_equal); | 1169 CHECK(results_equal); |
1192 | 1170 |
1193 env->Exit(); | 1171 env->Exit(); |
1194 Logger::TearDown(); | 1172 Logger::TearDown(); |
1195 i::FLAG_always_compact = saved_always_compact; | 1173 i::FLAG_always_compact = saved_always_compact; |
1196 } | 1174 } |
1197 | 1175 |
1198 #endif // ENABLE_LOGGING_AND_PROFILING | 1176 #endif // ENABLE_LOGGING_AND_PROFILING |
OLD | NEW |