Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 1 | // Copyright 2006-2009 the V8 project authors. All rights reserved. |
| 2 | // |
| 3 | // Tests of logging functions from log.h |
| 4 | |
| 5 | #ifdef ENABLE_LOGGING_AND_PROFILING |
| 6 | |
| 7 | #ifdef __linux__ |
| 8 | #include <math.h> |
| 9 | #include <pthread.h> |
| 10 | #include <signal.h> |
| 11 | #include <unistd.h> |
| 12 | #endif // __linux__ |
| 13 | |
| 14 | #include "v8.h" |
| 15 | #include "log.h" |
Steve Block | 6ded16b | 2010-05-10 14:33:55 +0100 | [diff] [blame] | 16 | #include "cpu-profiler.h" |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 17 | #include "v8threads.h" |
| 18 | #include "cctest.h" |
Ben Murdoch | b0fe162 | 2011-05-05 13:52:32 +0100 | [diff] [blame] | 19 | #include "vm-state-inl.h" |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 20 | |
| 21 | using v8::internal::Address; |
| 22 | using v8::internal::EmbeddedVector; |
| 23 | using v8::internal::Logger; |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 24 | using v8::internal::StrLength; |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 25 | |
| 26 | namespace i = v8::internal; |
| 27 | |
| 28 | static void SetUp() { |
| 29 | // Log to memory buffer. |
| 30 | i::FLAG_logfile = "*"; |
| 31 | i::FLAG_log = true; |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 32 | LOGGER->Setup(); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 33 | } |
| 34 | |
| 35 | static void TearDown() { |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 36 | LOGGER->TearDown(); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 37 | } |
| 38 | |
| 39 | |
| 40 | TEST(EmptyLog) { |
| 41 | SetUp(); |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 42 | CHECK_EQ(0, LOGGER->GetLogLines(0, NULL, 0)); |
| 43 | CHECK_EQ(0, LOGGER->GetLogLines(100, NULL, 0)); |
| 44 | CHECK_EQ(0, LOGGER->GetLogLines(0, NULL, 100)); |
| 45 | CHECK_EQ(0, LOGGER->GetLogLines(100, NULL, 100)); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 46 | TearDown(); |
| 47 | } |
| 48 | |
| 49 | |
| 50 | TEST(GetMessages) { |
| 51 | SetUp(); |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 52 | LOGGER->StringEvent("aaa", "bbb"); |
| 53 | LOGGER->StringEvent("cccc", "dddd"); |
| 54 | CHECK_EQ(0, LOGGER->GetLogLines(0, NULL, 0)); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 55 | char log_lines[100]; |
| 56 | memset(log_lines, 0, sizeof(log_lines)); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 57 | // See Logger::StringEvent. |
| 58 | const char* line_1 = "aaa,\"bbb\"\n"; |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 59 | const int line_1_len = StrLength(line_1); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 60 | // The exact size. |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 61 | CHECK_EQ(line_1_len, LOGGER->GetLogLines(0, log_lines, line_1_len)); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 62 | CHECK_EQ(line_1, log_lines); |
| 63 | memset(log_lines, 0, sizeof(log_lines)); |
| 64 | // A bit more than the first line length. |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 65 | CHECK_EQ(line_1_len, LOGGER->GetLogLines(0, log_lines, line_1_len + 3)); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 66 | log_lines[line_1_len] = '\0'; |
| 67 | CHECK_EQ(line_1, log_lines); |
| 68 | memset(log_lines, 0, sizeof(log_lines)); |
| 69 | const char* line_2 = "cccc,\"dddd\"\n"; |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 70 | const int line_2_len = StrLength(line_2); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 71 | // Now start with line_2 beginning. |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 72 | CHECK_EQ(0, LOGGER->GetLogLines(line_1_len, log_lines, 0)); |
| 73 | CHECK_EQ(line_2_len, LOGGER->GetLogLines(line_1_len, log_lines, line_2_len)); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 74 | CHECK_EQ(line_2, log_lines); |
| 75 | memset(log_lines, 0, sizeof(log_lines)); |
| 76 | CHECK_EQ(line_2_len, |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 77 | LOGGER->GetLogLines(line_1_len, log_lines, line_2_len + 3)); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 78 | CHECK_EQ(line_2, log_lines); |
| 79 | memset(log_lines, 0, sizeof(log_lines)); |
| 80 | // Now get entire buffer contents. |
| 81 | const char* all_lines = "aaa,\"bbb\"\ncccc,\"dddd\"\n"; |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 82 | const int all_lines_len = StrLength(all_lines); |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 83 | CHECK_EQ(all_lines_len, LOGGER->GetLogLines(0, log_lines, all_lines_len)); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 84 | CHECK_EQ(all_lines, log_lines); |
| 85 | memset(log_lines, 0, sizeof(log_lines)); |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 86 | CHECK_EQ(all_lines_len, LOGGER->GetLogLines(0, log_lines, all_lines_len + 3)); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 87 | CHECK_EQ(all_lines, log_lines); |
| 88 | memset(log_lines, 0, sizeof(log_lines)); |
| 89 | TearDown(); |
| 90 | } |
| 91 | |
| 92 | |
| 93 | static int GetLogLines(int start_pos, i::Vector<char>* buffer) { |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 94 | return LOGGER->GetLogLines(start_pos, buffer->start(), buffer->length()); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 95 | } |
| 96 | |
| 97 | |
| 98 | TEST(BeyondWritePosition) { |
| 99 | SetUp(); |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 100 | LOGGER->StringEvent("aaa", "bbb"); |
| 101 | LOGGER->StringEvent("cccc", "dddd"); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 102 | // See Logger::StringEvent. |
| 103 | const char* all_lines = "aaa,\"bbb\"\ncccc,\"dddd\"\n"; |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 104 | const int all_lines_len = StrLength(all_lines); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 105 | EmbeddedVector<char, 100> buffer; |
| 106 | const int beyond_write_pos = all_lines_len; |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 107 | CHECK_EQ(0, LOGGER->GetLogLines(beyond_write_pos, buffer.start(), 1)); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 108 | CHECK_EQ(0, GetLogLines(beyond_write_pos, &buffer)); |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 109 | CHECK_EQ(0, LOGGER->GetLogLines(beyond_write_pos + 1, buffer.start(), 1)); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 110 | CHECK_EQ(0, GetLogLines(beyond_write_pos + 1, &buffer)); |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 111 | CHECK_EQ(0, LOGGER->GetLogLines(beyond_write_pos + 100, buffer.start(), 1)); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 112 | CHECK_EQ(0, GetLogLines(beyond_write_pos + 100, &buffer)); |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 113 | CHECK_EQ(0, LOGGER->GetLogLines(10 * 1024 * 1024, buffer.start(), 1)); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 114 | CHECK_EQ(0, GetLogLines(10 * 1024 * 1024, &buffer)); |
| 115 | TearDown(); |
| 116 | } |
| 117 | |
| 118 | |
| 119 | TEST(MemoryLoggingTurnedOff) { |
| 120 | // Log to stdout |
| 121 | i::FLAG_logfile = "-"; |
| 122 | i::FLAG_log = true; |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 123 | LOGGER->Setup(); |
| 124 | CHECK_EQ(0, LOGGER->GetLogLines(0, NULL, 0)); |
| 125 | CHECK_EQ(0, LOGGER->GetLogLines(100, NULL, 0)); |
| 126 | CHECK_EQ(0, LOGGER->GetLogLines(0, NULL, 100)); |
| 127 | CHECK_EQ(0, LOGGER->GetLogLines(100, NULL, 100)); |
| 128 | LOGGER->TearDown(); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 129 | } |
| 130 | |
| 131 | |
| 132 | static void CompileAndRunScript(const char *src) { |
| 133 | v8::Script::Compile(v8::String::New(src))->Run(); |
| 134 | } |
| 135 | |
| 136 | |
| 137 | namespace v8 { |
| 138 | namespace internal { |
| 139 | |
| 140 | class LoggerTestHelper : public AllStatic { |
| 141 | public: |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 142 | static bool IsSamplerActive() { return LOGGER->IsProfilerSamplerActive(); } |
Shimeng (Simon) Wang | 8a31eba | 2010-12-06 19:01:33 -0800 | [diff] [blame] | 143 | static void ResetSamplesTaken() { |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 144 | reinterpret_cast<Sampler*>(LOGGER->ticker_)->ResetSamplesTaken(); |
Shimeng (Simon) Wang | 8a31eba | 2010-12-06 19:01:33 -0800 | [diff] [blame] | 145 | } |
| 146 | static bool has_samples_taken() { |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 147 | return reinterpret_cast<Sampler*>(LOGGER->ticker_)->samples_taken() > 0; |
Shimeng (Simon) Wang | 8a31eba | 2010-12-06 19:01:33 -0800 | [diff] [blame] | 148 | } |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 149 | }; |
| 150 | |
| 151 | } // namespace v8::internal |
| 152 | } // namespace v8 |
| 153 | |
| 154 | using v8::internal::LoggerTestHelper; |
| 155 | |
| 156 | |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 157 | namespace { |
| 158 | |
| 159 | class ScopedLoggerInitializer { |
| 160 | public: |
Steve Block | 6ded16b | 2010-05-10 14:33:55 +0100 | [diff] [blame] | 161 | explicit ScopedLoggerInitializer(bool prof_lazy) |
| 162 | : saved_prof_lazy_(i::FLAG_prof_lazy), |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 163 | saved_prof_(i::FLAG_prof), |
| 164 | saved_prof_auto_(i::FLAG_prof_auto), |
Steve Block | 6ded16b | 2010-05-10 14:33:55 +0100 | [diff] [blame] | 165 | trick_to_run_init_flags_(init_flags_(prof_lazy)), |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 166 | need_to_set_up_logger_(i::V8::IsRunning()), |
| 167 | scope_(), |
| 168 | env_(v8::Context::New()) { |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 169 | if (need_to_set_up_logger_) LOGGER->Setup(); |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 170 | env_->Enter(); |
| 171 | } |
| 172 | |
| 173 | ~ScopedLoggerInitializer() { |
| 174 | env_->Exit(); |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 175 | LOGGER->TearDown(); |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 176 | i::FLAG_prof_lazy = saved_prof_lazy_; |
| 177 | i::FLAG_prof = saved_prof_; |
| 178 | i::FLAG_prof_auto = saved_prof_auto_; |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 179 | } |
| 180 | |
| 181 | v8::Handle<v8::Context>& env() { return env_; } |
| 182 | |
| 183 | private: |
Steve Block | 6ded16b | 2010-05-10 14:33:55 +0100 | [diff] [blame] | 184 | static bool init_flags_(bool prof_lazy) { |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 185 | i::FLAG_prof = true; |
| 186 | i::FLAG_prof_lazy = prof_lazy; |
| 187 | i::FLAG_prof_auto = false; |
| 188 | i::FLAG_logfile = "*"; |
| 189 | return prof_lazy; |
| 190 | } |
| 191 | |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 192 | const bool saved_prof_lazy_; |
| 193 | const bool saved_prof_; |
| 194 | const bool saved_prof_auto_; |
| 195 | const bool trick_to_run_init_flags_; |
| 196 | const bool need_to_set_up_logger_; |
| 197 | v8::HandleScope scope_; |
| 198 | v8::Handle<v8::Context> env_; |
| 199 | |
| 200 | DISALLOW_COPY_AND_ASSIGN(ScopedLoggerInitializer); |
| 201 | }; |
| 202 | |
| 203 | |
| 204 | class LogBufferMatcher { |
| 205 | public: |
| 206 | LogBufferMatcher() { |
| 207 | // Skip all initially logged stuff. |
| 208 | log_pos_ = GetLogLines(0, &buffer_); |
| 209 | } |
| 210 | |
| 211 | int log_pos() { return log_pos_; } |
| 212 | |
| 213 | int GetNextChunk() { |
| 214 | int chunk_size = GetLogLines(log_pos_, &buffer_); |
| 215 | CHECK_GT(buffer_.length(), chunk_size); |
| 216 | buffer_[chunk_size] = '\0'; |
| 217 | log_pos_ += chunk_size; |
| 218 | return chunk_size; |
| 219 | } |
| 220 | |
| 221 | const char* Find(const char* substr) { |
| 222 | return strstr(buffer_.start(), substr); |
| 223 | } |
| 224 | |
| 225 | const char* Find(const i::Vector<char>& substr) { |
| 226 | return Find(substr.start()); |
| 227 | } |
| 228 | |
| 229 | bool IsInSequence(const char* s1, const char* s2) { |
| 230 | const char* s1_pos = Find(s1); |
| 231 | const char* s2_pos = Find(s2); |
| 232 | CHECK_NE(NULL, s1_pos); |
| 233 | CHECK_NE(NULL, s2_pos); |
| 234 | return s1_pos < s2_pos; |
| 235 | } |
| 236 | |
| 237 | void PrintBuffer() { |
| 238 | puts(buffer_.start()); |
| 239 | } |
| 240 | |
| 241 | private: |
| 242 | EmbeddedVector<char, 102400> buffer_; |
| 243 | int log_pos_; |
| 244 | }; |
| 245 | |
| 246 | } // namespace |
| 247 | |
| 248 | |
| 249 | static void CheckThatProfilerWorks(LogBufferMatcher* matcher) { |
Ben Murdoch | b0fe162 | 2011-05-05 13:52:32 +0100 | [diff] [blame] | 250 | CHECK(i::RuntimeProfiler::IsEnabled() || |
| 251 | !LoggerTestHelper::IsSamplerActive()); |
Shimeng (Simon) Wang | 8a31eba | 2010-12-06 19:01:33 -0800 | [diff] [blame] | 252 | LoggerTestHelper::ResetSamplesTaken(); |
| 253 | |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 254 | LOGGER->ResumeProfiler(v8::PROFILER_MODULE_CPU, 0); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 255 | CHECK(LoggerTestHelper::IsSamplerActive()); |
| 256 | |
| 257 | // Verify that the current map of compiled functions has been logged. |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 258 | CHECK_GT(matcher->GetNextChunk(), 0); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 259 | const char* code_creation = "\ncode-creation,"; // eq. to /^code-creation,/ |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 260 | CHECK_NE(NULL, matcher->Find(code_creation)); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 261 | |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 262 | // Force compiler to generate new code by parametrizing source. |
| 263 | EmbeddedVector<char, 100> script_src; |
| 264 | i::OS::SNPrintF(script_src, |
Leon Clarke | d91b9f7 | 2010-01-27 17:25:45 +0000 | [diff] [blame] | 265 | "function f%d(x) { return %d * x; }" |
| 266 | "for (var i = 0; i < 10000; ++i) { f%d(i); }", |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 267 | matcher->log_pos(), matcher->log_pos(), matcher->log_pos()); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 268 | // Run code for 200 msecs to get some ticks. |
| 269 | const double end_time = i::OS::TimeCurrentMillis() + 200; |
| 270 | while (i::OS::TimeCurrentMillis() < end_time) { |
| 271 | CompileAndRunScript(script_src.start()); |
| 272 | // Yield CPU to give Profiler thread a chance to process ticks. |
| 273 | i::OS::Sleep(1); |
| 274 | } |
| 275 | |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 276 | LOGGER->PauseProfiler(v8::PROFILER_MODULE_CPU, 0); |
Ben Murdoch | b0fe162 | 2011-05-05 13:52:32 +0100 | [diff] [blame] | 277 | CHECK(i::RuntimeProfiler::IsEnabled() || |
| 278 | !LoggerTestHelper::IsSamplerActive()); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 279 | |
| 280 | // Wait 50 msecs to allow Profiler thread to process the last |
| 281 | // tick sample it has got. |
| 282 | i::OS::Sleep(50); |
| 283 | |
| 284 | // Now we must have compiler and tick records. |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 285 | CHECK_GT(matcher->GetNextChunk(), 0); |
| 286 | matcher->PrintBuffer(); |
| 287 | CHECK_NE(NULL, matcher->Find(code_creation)); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 288 | const char* tick = "\ntick,"; |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 289 | const bool ticks_found = matcher->Find(tick) != NULL; |
Shimeng (Simon) Wang | 8a31eba | 2010-12-06 19:01:33 -0800 | [diff] [blame] | 290 | CHECK_EQ(LoggerTestHelper::has_samples_taken(), ticks_found); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 291 | } |
| 292 | |
| 293 | |
| 294 | TEST(ProfLazyMode) { |
Steve Block | 6ded16b | 2010-05-10 14:33:55 +0100 | [diff] [blame] | 295 | ScopedLoggerInitializer initialize_logger(true); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 296 | |
Ben Murdoch | b0fe162 | 2011-05-05 13:52:32 +0100 | [diff] [blame] | 297 | if (!i::V8::UseCrankshaft()) return; |
| 298 | |
| 299 | // No sampling should happen prior to resuming profiler unless we |
| 300 | // are runtime profiling. |
| 301 | CHECK(i::RuntimeProfiler::IsEnabled() || |
| 302 | !LoggerTestHelper::IsSamplerActive()); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 303 | |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 304 | LogBufferMatcher matcher; |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 305 | // Nothing must be logged until profiling is resumed. |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 306 | CHECK_EQ(0, matcher.log_pos()); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 307 | |
| 308 | CompileAndRunScript("var a = (function(x) { return x + 1; })(10);"); |
| 309 | |
| 310 | // Nothing must be logged while profiling is suspended. |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 311 | CHECK_EQ(0, matcher.GetNextChunk()); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 312 | |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 313 | CheckThatProfilerWorks(&matcher); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 314 | |
| 315 | CompileAndRunScript("var a = (function(x) { return x + 1; })(10);"); |
| 316 | |
| 317 | // No new data beyond last retrieved position. |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 318 | CHECK_EQ(0, matcher.GetNextChunk()); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 319 | |
| 320 | // Check that profiling can be resumed again. |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 321 | CheckThatProfilerWorks(&matcher); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 322 | } |
| 323 | |
| 324 | |
John Reck | 5913587 | 2010-11-02 12:39:01 -0700 | [diff] [blame] | 325 | // BUG(913). Need to implement support for profiling multiple VM threads. |
| 326 | #if 0 |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 327 | |
| 328 | namespace { |
| 329 | |
| 330 | class LoopingThread : public v8::internal::Thread { |
| 331 | public: |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 332 | explicit LoopingThread(v8::internal::Isolate* isolate) |
| 333 | : v8::internal::Thread(isolate), |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 334 | semaphore_(v8::internal::OS::CreateSemaphore(0)), |
| 335 | run_(true) { |
| 336 | } |
| 337 | |
| 338 | virtual ~LoopingThread() { delete semaphore_; } |
| 339 | |
| 340 | void Run() { |
| 341 | self_ = pthread_self(); |
| 342 | RunLoop(); |
| 343 | } |
| 344 | |
| 345 | void SendSigProf() { pthread_kill(self_, SIGPROF); } |
| 346 | |
| 347 | void Stop() { run_ = false; } |
| 348 | |
| 349 | bool WaitForRunning() { return semaphore_->Wait(1000000); } |
| 350 | |
| 351 | protected: |
| 352 | bool IsRunning() { return run_; } |
| 353 | |
| 354 | virtual void RunLoop() = 0; |
| 355 | |
| 356 | void SetV8ThreadId() { |
| 357 | v8_thread_id_ = v8::V8::GetCurrentThreadId(); |
| 358 | } |
| 359 | |
| 360 | void SignalRunning() { semaphore_->Signal(); } |
| 361 | |
| 362 | private: |
| 363 | v8::internal::Semaphore* semaphore_; |
| 364 | bool run_; |
| 365 | pthread_t self_; |
| 366 | int v8_thread_id_; |
| 367 | }; |
| 368 | |
| 369 | |
| 370 | class LoopingJsThread : public LoopingThread { |
| 371 | public: |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 372 | explicit LoopingJsThread(v8::internal::Isolate* isolate) |
| 373 | : LoopingThread(isolate) { } |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 374 | void RunLoop() { |
Steve Block | 6ded16b | 2010-05-10 14:33:55 +0100 | [diff] [blame] | 375 | v8::Locker locker; |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 376 | CHECK(i::Isolate::Current() != NULL); |
| 377 | CHECK_GT(i::Isolate::Current()->thread_manager()->CurrentId(), 0); |
Steve Block | 6ded16b | 2010-05-10 14:33:55 +0100 | [diff] [blame] | 378 | SetV8ThreadId(); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 379 | while (IsRunning()) { |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 380 | v8::HandleScope scope; |
| 381 | v8::Persistent<v8::Context> context = v8::Context::New(); |
Steve Block | 6ded16b | 2010-05-10 14:33:55 +0100 | [diff] [blame] | 382 | CHECK(!context.IsEmpty()); |
| 383 | { |
| 384 | v8::Context::Scope context_scope(context); |
| 385 | SignalRunning(); |
| 386 | CompileAndRunScript( |
| 387 | "var j; for (var i=0; i<10000; ++i) { j = Math.sin(i); }"); |
| 388 | } |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 389 | context.Dispose(); |
| 390 | i::OS::Sleep(1); |
| 391 | } |
| 392 | } |
| 393 | }; |
| 394 | |
| 395 | |
| 396 | class LoopingNonJsThread : public LoopingThread { |
| 397 | public: |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 398 | explicit LoopingNonJsThread(v8::internal::Isolate* isolate) |
| 399 | : LoopingThread(isolate) { } |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 400 | void RunLoop() { |
| 401 | v8::Locker locker; |
| 402 | v8::Unlocker unlocker; |
| 403 | // Now thread has V8's id, but will not run VM code. |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 404 | CHECK(i::Isolate::Current() != NULL); |
| 405 | CHECK_GT(i::Isolate::Current()->thread_manager()->CurrentId(), 0); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 406 | double i = 10; |
| 407 | SignalRunning(); |
| 408 | while (IsRunning()) { |
| 409 | i = sin(i); |
| 410 | i::OS::Sleep(1); |
| 411 | } |
| 412 | } |
| 413 | }; |
| 414 | |
| 415 | |
| 416 | class TestSampler : public v8::internal::Sampler { |
| 417 | public: |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 418 | explicit TestSampler(v8::internal::Isolate* isolate) |
| 419 | : Sampler(isolate, 0, true, true), |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 420 | semaphore_(v8::internal::OS::CreateSemaphore(0)), |
| 421 | was_sample_stack_called_(false) { |
| 422 | } |
| 423 | |
| 424 | ~TestSampler() { delete semaphore_; } |
| 425 | |
| 426 | void SampleStack(v8::internal::TickSample*) { |
| 427 | was_sample_stack_called_ = true; |
| 428 | } |
| 429 | |
| 430 | void Tick(v8::internal::TickSample*) { semaphore_->Signal(); } |
| 431 | |
| 432 | bool WaitForTick() { return semaphore_->Wait(1000000); } |
| 433 | |
| 434 | void Reset() { was_sample_stack_called_ = false; } |
| 435 | |
| 436 | bool WasSampleStackCalled() { return was_sample_stack_called_; } |
| 437 | |
| 438 | private: |
| 439 | v8::internal::Semaphore* semaphore_; |
| 440 | bool was_sample_stack_called_; |
| 441 | }; |
| 442 | |
| 443 | |
| 444 | } // namespace |
| 445 | |
| 446 | TEST(ProfMultipleThreads) { |
Ben Murdoch | b0fe162 | 2011-05-05 13:52:32 +0100 | [diff] [blame] | 447 | TestSampler* sampler = NULL; |
| 448 | { |
| 449 | v8::Locker locker; |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 450 | sampler = new TestSampler(v8::internal::Isolate::Current()); |
Ben Murdoch | b0fe162 | 2011-05-05 13:52:32 +0100 | [diff] [blame] | 451 | sampler->Start(); |
| 452 | CHECK(sampler->IsActive()); |
| 453 | } |
| 454 | |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 455 | LoopingJsThread jsThread(v8::internal::Isolate::Current()); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 456 | jsThread.Start(); |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 457 | LoopingNonJsThread nonJsThread(v8::internal::Isolate::Current()); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 458 | nonJsThread.Start(); |
| 459 | |
Ben Murdoch | b0fe162 | 2011-05-05 13:52:32 +0100 | [diff] [blame] | 460 | CHECK(!sampler->WasSampleStackCalled()); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 461 | jsThread.WaitForRunning(); |
| 462 | jsThread.SendSigProf(); |
Ben Murdoch | b0fe162 | 2011-05-05 13:52:32 +0100 | [diff] [blame] | 463 | CHECK(sampler->WaitForTick()); |
| 464 | CHECK(sampler->WasSampleStackCalled()); |
| 465 | sampler->Reset(); |
| 466 | CHECK(!sampler->WasSampleStackCalled()); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 467 | nonJsThread.WaitForRunning(); |
| 468 | nonJsThread.SendSigProf(); |
Ben Murdoch | b0fe162 | 2011-05-05 13:52:32 +0100 | [diff] [blame] | 469 | CHECK(!sampler->WaitForTick()); |
| 470 | CHECK(!sampler->WasSampleStackCalled()); |
| 471 | sampler->Stop(); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 472 | |
| 473 | jsThread.Stop(); |
| 474 | nonJsThread.Stop(); |
| 475 | jsThread.Join(); |
| 476 | nonJsThread.Join(); |
Ben Murdoch | b0fe162 | 2011-05-05 13:52:32 +0100 | [diff] [blame] | 477 | |
| 478 | delete sampler; |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 479 | } |
| 480 | |
| 481 | #endif // __linux__ |
| 482 | |
| 483 | |
Steve Block | 3ce2e20 | 2009-11-05 08:53:23 +0000 | [diff] [blame] | 484 | // Test for issue http://crbug.com/23768 in Chromium. |
| 485 | // Heap can contain scripts with already disposed external sources. |
| 486 | // We need to verify that LogCompiledFunctions doesn't crash on them. |
| 487 | namespace { |
| 488 | |
| 489 | class SimpleExternalString : public v8::String::ExternalStringResource { |
| 490 | public: |
| 491 | explicit SimpleExternalString(const char* source) |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 492 | : utf_source_(StrLength(source)) { |
Steve Block | 3ce2e20 | 2009-11-05 08:53:23 +0000 | [diff] [blame] | 493 | for (int i = 0; i < utf_source_.length(); ++i) |
| 494 | utf_source_[i] = source[i]; |
| 495 | } |
| 496 | virtual ~SimpleExternalString() {} |
| 497 | virtual size_t length() const { return utf_source_.length(); } |
| 498 | virtual const uint16_t* data() const { return utf_source_.start(); } |
| 499 | private: |
| 500 | i::ScopedVector<uint16_t> utf_source_; |
| 501 | }; |
| 502 | |
| 503 | } // namespace |
| 504 | |
| 505 | TEST(Issue23768) { |
| 506 | v8::HandleScope scope; |
| 507 | v8::Handle<v8::Context> env = v8::Context::New(); |
| 508 | env->Enter(); |
| 509 | |
| 510 | SimpleExternalString source_ext_str("(function ext() {})();"); |
| 511 | v8::Local<v8::String> source = v8::String::NewExternal(&source_ext_str); |
| 512 | // Script needs to have a name in order to trigger InitLineEnds execution. |
| 513 | v8::Handle<v8::String> origin = v8::String::New("issue-23768-test"); |
| 514 | v8::Handle<v8::Script> evil_script = v8::Script::Compile(source, origin); |
| 515 | CHECK(!evil_script.IsEmpty()); |
| 516 | CHECK(!evil_script->Run().IsEmpty()); |
| 517 | i::Handle<i::ExternalTwoByteString> i_source( |
| 518 | i::ExternalTwoByteString::cast(*v8::Utils::OpenHandle(*source))); |
| 519 | // This situation can happen if source was an external string disposed |
| 520 | // by its owner. |
| 521 | i_source->set_resource(NULL); |
| 522 | |
| 523 | // Must not crash. |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 524 | LOGGER->LogCompiledFunctions(); |
Steve Block | 3ce2e20 | 2009-11-05 08:53:23 +0000 | [diff] [blame] | 525 | } |
| 526 | |
| 527 | |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 528 | static v8::Handle<v8::Value> ObjMethod1(const v8::Arguments& args) { |
| 529 | return v8::Handle<v8::Value>(); |
| 530 | } |
| 531 | |
| 532 | TEST(LogCallbacks) { |
Steve Block | 6ded16b | 2010-05-10 14:33:55 +0100 | [diff] [blame] | 533 | ScopedLoggerInitializer initialize_logger(false); |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 534 | LogBufferMatcher matcher; |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 535 | |
| 536 | v8::Persistent<v8::FunctionTemplate> obj = |
| 537 | v8::Persistent<v8::FunctionTemplate>::New(v8::FunctionTemplate::New()); |
| 538 | obj->SetClassName(v8::String::New("Obj")); |
| 539 | v8::Handle<v8::ObjectTemplate> proto = obj->PrototypeTemplate(); |
| 540 | v8::Local<v8::Signature> signature = v8::Signature::New(obj); |
| 541 | proto->Set(v8::String::New("method1"), |
| 542 | v8::FunctionTemplate::New(ObjMethod1, |
| 543 | v8::Handle<v8::Value>(), |
| 544 | signature), |
| 545 | static_cast<v8::PropertyAttribute>(v8::DontDelete)); |
| 546 | |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 547 | initialize_logger.env()->Global()->Set(v8_str("Obj"), obj->GetFunction()); |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 548 | CompileAndRunScript("Obj.prototype.method1.toString();"); |
| 549 | |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 550 | LOGGER->LogCompiledFunctions(); |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 551 | CHECK_GT(matcher.GetNextChunk(), 0); |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 552 | |
| 553 | const char* callback_rec = "code-creation,Callback,"; |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 554 | char* pos = const_cast<char*>(matcher.Find(callback_rec)); |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 555 | CHECK_NE(NULL, pos); |
| 556 | pos += strlen(callback_rec); |
| 557 | EmbeddedVector<char, 100> ref_data; |
| 558 | i::OS::SNPrintF(ref_data, |
| 559 | "0x%" V8PRIxPTR ",1,\"method1\"", ObjMethod1); |
| 560 | *(pos + strlen(ref_data.start())) = '\0'; |
| 561 | CHECK_EQ(ref_data.start(), pos); |
| 562 | |
| 563 | obj.Dispose(); |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 564 | } |
| 565 | |
| 566 | |
| 567 | static v8::Handle<v8::Value> Prop1Getter(v8::Local<v8::String> property, |
| 568 | const v8::AccessorInfo& info) { |
| 569 | return v8::Handle<v8::Value>(); |
| 570 | } |
| 571 | |
| 572 | static void Prop1Setter(v8::Local<v8::String> property, |
| 573 | v8::Local<v8::Value> value, |
| 574 | const v8::AccessorInfo& info) { |
| 575 | } |
| 576 | |
| 577 | static v8::Handle<v8::Value> Prop2Getter(v8::Local<v8::String> property, |
| 578 | const v8::AccessorInfo& info) { |
| 579 | return v8::Handle<v8::Value>(); |
| 580 | } |
| 581 | |
| 582 | TEST(LogAccessorCallbacks) { |
Steve Block | 6ded16b | 2010-05-10 14:33:55 +0100 | [diff] [blame] | 583 | ScopedLoggerInitializer initialize_logger(false); |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 584 | LogBufferMatcher matcher; |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 585 | |
| 586 | v8::Persistent<v8::FunctionTemplate> obj = |
| 587 | v8::Persistent<v8::FunctionTemplate>::New(v8::FunctionTemplate::New()); |
| 588 | obj->SetClassName(v8::String::New("Obj")); |
| 589 | v8::Handle<v8::ObjectTemplate> inst = obj->InstanceTemplate(); |
| 590 | inst->SetAccessor(v8::String::New("prop1"), Prop1Getter, Prop1Setter); |
| 591 | inst->SetAccessor(v8::String::New("prop2"), Prop2Getter); |
| 592 | |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 593 | LOGGER->LogAccessorCallbacks(); |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 594 | CHECK_GT(matcher.GetNextChunk(), 0); |
| 595 | matcher.PrintBuffer(); |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 596 | |
| 597 | EmbeddedVector<char, 100> prop1_getter_record; |
| 598 | i::OS::SNPrintF(prop1_getter_record, |
| 599 | "code-creation,Callback,0x%" V8PRIxPTR ",1,\"get prop1\"", |
| 600 | Prop1Getter); |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 601 | CHECK_NE(NULL, matcher.Find(prop1_getter_record)); |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 602 | EmbeddedVector<char, 100> prop1_setter_record; |
| 603 | i::OS::SNPrintF(prop1_setter_record, |
| 604 | "code-creation,Callback,0x%" V8PRIxPTR ",1,\"set prop1\"", |
| 605 | Prop1Setter); |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 606 | CHECK_NE(NULL, matcher.Find(prop1_setter_record)); |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 607 | EmbeddedVector<char, 100> prop2_getter_record; |
| 608 | i::OS::SNPrintF(prop2_getter_record, |
| 609 | "code-creation,Callback,0x%" V8PRIxPTR ",1,\"get prop2\"", |
| 610 | Prop2Getter); |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 611 | CHECK_NE(NULL, matcher.Find(prop2_getter_record)); |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 612 | |
| 613 | obj.Dispose(); |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 614 | } |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 615 | |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 616 | |
| 617 | TEST(LogTags) { |
Steve Block | 6ded16b | 2010-05-10 14:33:55 +0100 | [diff] [blame] | 618 | ScopedLoggerInitializer initialize_logger(false); |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 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. |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 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()); |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 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. |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 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()); |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 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. |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 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()); |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 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. |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 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()); |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 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. |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 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()); |
Andrei Popescu | 402d937 | 2010-02-26 13:31:12 +0000 | [diff] [blame] | 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)); |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 700 | } |
| 701 | |
| 702 | |
Steve Block | 6ded16b | 2010-05-10 14:33:55 +0100 | [diff] [blame] | 703 | TEST(IsLoggingPreserved) { |
| 704 | ScopedLoggerInitializer initialize_logger(false); |
| 705 | |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 706 | CHECK(LOGGER->is_logging()); |
| 707 | LOGGER->ResumeProfiler(v8::PROFILER_MODULE_CPU, 1); |
| 708 | CHECK(LOGGER->is_logging()); |
| 709 | LOGGER->PauseProfiler(v8::PROFILER_MODULE_CPU, 1); |
| 710 | CHECK(LOGGER->is_logging()); |
Steve Block | 6ded16b | 2010-05-10 14:33:55 +0100 | [diff] [blame] | 711 | |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 712 | CHECK(LOGGER->is_logging()); |
| 713 | LOGGER->ResumeProfiler( |
Steve Block | 6ded16b | 2010-05-10 14:33:55 +0100 | [diff] [blame] | 714 | v8::PROFILER_MODULE_HEAP_STATS | v8::PROFILER_MODULE_JS_CONSTRUCTORS, 1); |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 715 | CHECK(LOGGER->is_logging()); |
| 716 | LOGGER->PauseProfiler( |
Steve Block | 6ded16b | 2010-05-10 14:33:55 +0100 | [diff] [blame] | 717 | v8::PROFILER_MODULE_HEAP_STATS | v8::PROFILER_MODULE_JS_CONSTRUCTORS, 1); |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 718 | CHECK(LOGGER->is_logging()); |
Steve Block | 6ded16b | 2010-05-10 14:33:55 +0100 | [diff] [blame] | 719 | |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 720 | CHECK(LOGGER->is_logging()); |
| 721 | LOGGER->ResumeProfiler( |
Steve Block | 6ded16b | 2010-05-10 14:33:55 +0100 | [diff] [blame] | 722 | v8::PROFILER_MODULE_CPU | |
| 723 | v8::PROFILER_MODULE_HEAP_STATS | v8::PROFILER_MODULE_JS_CONSTRUCTORS, 1); |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 724 | CHECK(LOGGER->is_logging()); |
| 725 | LOGGER->PauseProfiler( |
Steve Block | 6ded16b | 2010-05-10 14:33:55 +0100 | [diff] [blame] | 726 | v8::PROFILER_MODULE_CPU | |
| 727 | v8::PROFILER_MODULE_HEAP_STATS | v8::PROFILER_MODULE_JS_CONSTRUCTORS, 1); |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 728 | CHECK(LOGGER->is_logging()); |
Steve Block | 6ded16b | 2010-05-10 14:33:55 +0100 | [diff] [blame] | 729 | } |
| 730 | |
| 731 | |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 732 | static inline bool IsStringEqualTo(const char* r, const char* s) { |
| 733 | return strncmp(r, s, strlen(r)) == 0; |
| 734 | } |
| 735 | |
| 736 | |
| 737 | static bool Consume(const char* str, char** buf) { |
| 738 | if (IsStringEqualTo(str, *buf)) { |
| 739 | *buf += strlen(str); |
| 740 | return true; |
| 741 | } |
| 742 | return false; |
| 743 | } |
| 744 | |
| 745 | |
| 746 | namespace { |
| 747 | |
| 748 | // A code entity is a pointer to a position of code-creation event in buffer log |
| 749 | // offset to a point where entity size begins, i.e.: '255,"func"\n'. This makes |
| 750 | // comparing code entities pretty easy. |
| 751 | typedef char* CodeEntityInfo; |
| 752 | |
| 753 | class Interval { |
| 754 | public: |
| 755 | Interval() |
| 756 | : min_addr_(reinterpret_cast<Address>(-1)), |
| 757 | max_addr_(reinterpret_cast<Address>(0)), next_(NULL) {} |
| 758 | |
| 759 | ~Interval() { delete next_; } |
| 760 | |
| 761 | size_t Length() { |
| 762 | size_t result = max_addr_ - min_addr_ + 1; |
| 763 | if (next_ != NULL) result += next_->Length(); |
| 764 | return result; |
| 765 | } |
| 766 | |
| 767 | void CloneFrom(Interval* src) { |
| 768 | while (src != NULL) { |
| 769 | RegisterAddress(src->min_addr_); |
| 770 | RegisterAddress(src->max_addr_); |
| 771 | src = src->next_; |
| 772 | } |
| 773 | } |
| 774 | |
| 775 | bool Contains(Address addr) { |
| 776 | if (min_addr_ <= addr && addr <= max_addr_) { |
| 777 | return true; |
| 778 | } |
| 779 | if (next_ != NULL) { |
| 780 | return next_->Contains(addr); |
| 781 | } else { |
| 782 | return false; |
| 783 | } |
| 784 | } |
| 785 | |
| 786 | size_t GetIndex(Address addr) { |
| 787 | if (min_addr_ <= addr && addr <= max_addr_) { |
| 788 | return addr - min_addr_; |
| 789 | } |
| 790 | CHECK_NE(NULL, next_); |
| 791 | return (max_addr_ - min_addr_ + 1) + next_->GetIndex(addr); |
| 792 | } |
| 793 | |
| 794 | Address GetMinAddr() { |
| 795 | return next_ == NULL ? min_addr_ : i::Min(min_addr_, next_->GetMinAddr()); |
| 796 | } |
| 797 | |
| 798 | Address GetMaxAddr() { |
| 799 | return next_ == NULL ? max_addr_ : i::Max(max_addr_, next_->GetMaxAddr()); |
| 800 | } |
| 801 | |
| 802 | void RegisterAddress(Address addr) { |
| 803 | if (min_addr_ == reinterpret_cast<Address>(-1) |
| 804 | || (size_t)(addr > min_addr_ ? |
| 805 | addr - min_addr_ : min_addr_ - addr) < MAX_DELTA) { |
| 806 | if (addr < min_addr_) min_addr_ = addr; |
| 807 | if (addr > max_addr_) max_addr_ = addr; |
| 808 | } else { |
| 809 | if (next_ == NULL) next_ = new Interval(); |
| 810 | next_->RegisterAddress(addr); |
| 811 | } |
| 812 | } |
| 813 | |
| 814 | Address raw_min_addr() { return min_addr_; } |
| 815 | |
| 816 | Address raw_max_addr() { return max_addr_; } |
| 817 | |
| 818 | Interval* get_next() { return next_; } |
| 819 | |
| 820 | private: |
| 821 | static const size_t MAX_DELTA = 0x100000; |
| 822 | Address min_addr_; |
| 823 | Address max_addr_; |
| 824 | Interval* next_; |
| 825 | }; |
| 826 | |
| 827 | |
| 828 | // A structure used to return log parsing results. |
| 829 | class ParseLogResult { |
| 830 | public: |
| 831 | ParseLogResult() |
| 832 | : entities_map(NULL), entities(NULL), |
| 833 | max_entities(0) {} |
| 834 | |
| 835 | ~ParseLogResult() { |
| 836 | i::DeleteArray(entities_map); |
| 837 | i::DeleteArray(entities); |
| 838 | } |
| 839 | |
| 840 | void AllocateEntities() { |
| 841 | // Make sure that the test doesn't operate on a bogus log. |
| 842 | CHECK_GT(max_entities, 0); |
| 843 | CHECK_GT(bounds.GetMinAddr(), 0); |
| 844 | CHECK_GT(bounds.GetMaxAddr(), bounds.GetMinAddr()); |
| 845 | |
| 846 | entities = i::NewArray<CodeEntityInfo>(max_entities); |
| 847 | for (int i = 0; i < max_entities; ++i) { |
| 848 | entities[i] = NULL; |
| 849 | } |
| 850 | const size_t map_length = bounds.Length(); |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 851 | entities_map = i::NewArray<int>(static_cast<int>(map_length)); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 852 | for (size_t i = 0; i < map_length; ++i) { |
| 853 | entities_map[i] = -1; |
| 854 | } |
| 855 | } |
| 856 | |
| 857 | bool HasIndexForAddress(Address addr) { |
| 858 | return bounds.Contains(addr); |
| 859 | } |
| 860 | |
| 861 | size_t GetIndexForAddress(Address addr) { |
| 862 | CHECK(HasIndexForAddress(addr)); |
| 863 | return bounds.GetIndex(addr); |
| 864 | } |
| 865 | |
| 866 | CodeEntityInfo GetEntity(Address addr) { |
| 867 | if (HasIndexForAddress(addr)) { |
| 868 | size_t idx = GetIndexForAddress(addr); |
| 869 | int item = entities_map[idx]; |
| 870 | return item != -1 ? entities[item] : NULL; |
| 871 | } |
| 872 | return NULL; |
| 873 | } |
| 874 | |
| 875 | void ParseAddress(char* start) { |
| 876 | Address addr = |
| 877 | reinterpret_cast<Address>(strtoul(start, NULL, 16)); // NOLINT |
| 878 | bounds.RegisterAddress(addr); |
| 879 | } |
| 880 | |
| 881 | Address ConsumeAddress(char** start) { |
| 882 | char* end_ptr; |
| 883 | Address addr = |
| 884 | reinterpret_cast<Address>(strtoul(*start, &end_ptr, 16)); // NOLINT |
| 885 | CHECK(HasIndexForAddress(addr)); |
| 886 | *start = end_ptr; |
| 887 | return addr; |
| 888 | } |
| 889 | |
| 890 | Interval bounds; |
| 891 | // Memory map of entities start addresses. |
| 892 | int* entities_map; |
| 893 | // An array of code entities. |
| 894 | CodeEntityInfo* entities; |
| 895 | // Maximal entities count. Actual entities count can be lower, |
| 896 | // empty entity slots are pointing to NULL. |
| 897 | int max_entities; |
| 898 | }; |
| 899 | |
| 900 | } // namespace |
| 901 | |
| 902 | |
| 903 | typedef void (*ParserBlock)(char* start, char* end, ParseLogResult* result); |
| 904 | |
| 905 | static void ParserCycle( |
| 906 | char* start, char* end, ParseLogResult* result, |
| 907 | ParserBlock block_creation, ParserBlock block_delete, |
| 908 | ParserBlock block_move) { |
| 909 | |
| 910 | const char* code_creation = "code-creation,"; |
| 911 | const char* code_delete = "code-delete,"; |
| 912 | const char* code_move = "code-move,"; |
| 913 | |
| 914 | const char* lazy_compile = "LazyCompile,"; |
| 915 | const char* script = "Script,"; |
| 916 | const char* function = "Function,"; |
| 917 | |
| 918 | while (start < end) { |
| 919 | if (Consume(code_creation, &start)) { |
| 920 | if (Consume(lazy_compile, &start) |
| 921 | || Consume(script, &start) |
| 922 | || Consume(function, &start)) { |
| 923 | block_creation(start, end, result); |
| 924 | } |
| 925 | } else if (Consume(code_delete, &start)) { |
| 926 | block_delete(start, end, result); |
| 927 | } else if (Consume(code_move, &start)) { |
| 928 | block_move(start, end, result); |
| 929 | } |
| 930 | while (start < end && *start != '\n') ++start; |
| 931 | ++start; |
| 932 | } |
| 933 | } |
| 934 | |
| 935 | |
| 936 | static void Pass1CodeCreation(char* start, char* end, ParseLogResult* result) { |
| 937 | result->ParseAddress(start); |
| 938 | ++result->max_entities; |
| 939 | } |
| 940 | |
| 941 | |
| 942 | static void Pass1CodeDelete(char* start, char* end, ParseLogResult* result) { |
| 943 | result->ParseAddress(start); |
| 944 | } |
| 945 | |
| 946 | |
| 947 | static void Pass1CodeMove(char* start, char* end, ParseLogResult* result) { |
| 948 | result->ParseAddress(start); |
| 949 | // Skip old address. |
| 950 | while (start < end && *start != ',') ++start; |
| 951 | CHECK_GT(end, start); |
| 952 | ++start; // Skip ','. |
| 953 | result->ParseAddress(start); |
| 954 | } |
| 955 | |
| 956 | |
| 957 | static void Pass2CodeCreation(char* start, char* end, ParseLogResult* result) { |
| 958 | Address addr = result->ConsumeAddress(&start); |
| 959 | CHECK_GT(end, start); |
| 960 | ++start; // Skip ','. |
| 961 | |
| 962 | size_t idx = result->GetIndexForAddress(addr); |
| 963 | result->entities_map[idx] = -1; |
| 964 | for (int i = 0; i < result->max_entities; ++i) { |
| 965 | // Find an empty slot and fill it. |
| 966 | if (result->entities[i] == NULL) { |
| 967 | result->entities[i] = start; |
| 968 | result->entities_map[idx] = i; |
| 969 | break; |
| 970 | } |
| 971 | } |
| 972 | // Make sure that a slot was found. |
| 973 | CHECK_GE(result->entities_map[idx], 0); |
| 974 | } |
| 975 | |
| 976 | |
| 977 | static void Pass2CodeDelete(char* start, char* end, ParseLogResult* result) { |
| 978 | Address addr = result->ConsumeAddress(&start); |
| 979 | size_t idx = result->GetIndexForAddress(addr); |
| 980 | // There can be code deletes that are not related to JS code. |
| 981 | if (result->entities_map[idx] >= 0) { |
| 982 | result->entities[result->entities_map[idx]] = NULL; |
| 983 | result->entities_map[idx] = -1; |
| 984 | } |
| 985 | } |
| 986 | |
| 987 | |
| 988 | static void Pass2CodeMove(char* start, char* end, ParseLogResult* result) { |
| 989 | Address from_addr = result->ConsumeAddress(&start); |
| 990 | CHECK_GT(end, start); |
| 991 | ++start; // Skip ','. |
| 992 | Address to_addr = result->ConsumeAddress(&start); |
| 993 | CHECK_GT(end, start); |
| 994 | |
| 995 | size_t from_idx = result->GetIndexForAddress(from_addr); |
| 996 | size_t to_idx = result->GetIndexForAddress(to_addr); |
| 997 | // There can be code moves that are not related to JS code. |
| 998 | if (from_idx != to_idx && result->entities_map[from_idx] >= 0) { |
| 999 | CHECK_EQ(-1, result->entities_map[to_idx]); |
| 1000 | result->entities_map[to_idx] = result->entities_map[from_idx]; |
| 1001 | result->entities_map[from_idx] = -1; |
| 1002 | }; |
| 1003 | } |
| 1004 | |
| 1005 | |
| 1006 | static void ParseLog(char* start, char* end, ParseLogResult* result) { |
| 1007 | // Pass 1: Calculate boundaries of addresses and entities count. |
| 1008 | ParserCycle(start, end, result, |
| 1009 | Pass1CodeCreation, Pass1CodeDelete, Pass1CodeMove); |
| 1010 | |
| 1011 | printf("min_addr: %p, max_addr: %p, entities: %d\n", |
| 1012 | result->bounds.GetMinAddr(), result->bounds.GetMaxAddr(), |
| 1013 | result->max_entities); |
| 1014 | |
| 1015 | result->AllocateEntities(); |
| 1016 | |
| 1017 | // Pass 2: Fill in code entries data. |
| 1018 | ParserCycle(start, end, result, |
| 1019 | Pass2CodeCreation, Pass2CodeDelete, Pass2CodeMove); |
| 1020 | } |
| 1021 | |
| 1022 | |
| 1023 | static inline void PrintCodeEntityInfo(CodeEntityInfo entity) { |
| 1024 | const int max_len = 50; |
| 1025 | if (entity != NULL) { |
| 1026 | char* eol = strchr(entity, '\n'); |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 1027 | int len = static_cast<int>(eol - entity); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 1028 | len = len <= max_len ? len : max_len; |
| 1029 | printf("%-*.*s ", max_len, len, entity); |
| 1030 | } else { |
| 1031 | printf("%*s", max_len + 1, ""); |
| 1032 | } |
| 1033 | } |
| 1034 | |
| 1035 | |
| 1036 | static void PrintCodeEntitiesInfo( |
| 1037 | bool is_equal, Address addr, |
| 1038 | CodeEntityInfo l_entity, CodeEntityInfo r_entity) { |
| 1039 | printf("%c %p ", is_equal ? ' ' : '*', addr); |
| 1040 | PrintCodeEntityInfo(l_entity); |
| 1041 | PrintCodeEntityInfo(r_entity); |
| 1042 | printf("\n"); |
| 1043 | } |
| 1044 | |
| 1045 | |
| 1046 | static inline int StrChrLen(const char* s, char c) { |
Steve Block | d0582a6 | 2009-12-15 09:54:21 +0000 | [diff] [blame] | 1047 | return static_cast<int>(strchr(s, c) - s); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 1048 | } |
| 1049 | |
| 1050 | |
| 1051 | static bool AreFuncSizesEqual(CodeEntityInfo ref_s, CodeEntityInfo new_s) { |
| 1052 | int ref_len = StrChrLen(ref_s, ','); |
| 1053 | int new_len = StrChrLen(new_s, ','); |
| 1054 | return ref_len == new_len && strncmp(ref_s, new_s, ref_len) == 0; |
| 1055 | } |
| 1056 | |
| 1057 | |
| 1058 | static bool AreFuncNamesEqual(CodeEntityInfo ref_s, CodeEntityInfo new_s) { |
| 1059 | // Skip size. |
| 1060 | ref_s = strchr(ref_s, ',') + 1; |
| 1061 | new_s = strchr(new_s, ',') + 1; |
Ben Murdoch | e0cee9b | 2011-05-25 10:26:03 +0100 | [diff] [blame] | 1062 | CHECK_EQ('"', ref_s[0]); |
| 1063 | CHECK_EQ('"', new_s[0]); |
| 1064 | int ref_len = StrChrLen(ref_s + 1, '\"'); |
| 1065 | int new_len = StrChrLen(new_s + 1, '\"'); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 1066 | // A special case for ErrorPrototype. Haven't yet figured out why they |
| 1067 | // are different. |
| 1068 | const char* error_prototype = "\"ErrorPrototype"; |
| 1069 | if (IsStringEqualTo(error_prototype, ref_s) |
| 1070 | && IsStringEqualTo(error_prototype, new_s)) { |
| 1071 | return true; |
| 1072 | } |
| 1073 | // Built-in objects have problems too. |
| 1074 | const char* built_ins[] = { |
| 1075 | "\"Boolean\"", "\"Function\"", "\"Number\"", |
| 1076 | "\"Object\"", "\"Script\"", "\"String\"" |
| 1077 | }; |
| 1078 | for (size_t i = 0; i < sizeof(built_ins) / sizeof(*built_ins); ++i) { |
| 1079 | if (IsStringEqualTo(built_ins[i], new_s)) { |
| 1080 | return true; |
| 1081 | } |
| 1082 | } |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 1083 | return ref_len == new_len && strncmp(ref_s, new_s, ref_len) == 0; |
| 1084 | } |
| 1085 | |
| 1086 | |
| 1087 | static bool AreEntitiesEqual(CodeEntityInfo ref_e, CodeEntityInfo new_e) { |
| 1088 | if (ref_e == NULL && new_e != NULL) return true; |
| 1089 | if (ref_e != NULL && new_e != NULL) { |
| 1090 | return AreFuncSizesEqual(ref_e, new_e) && AreFuncNamesEqual(ref_e, new_e); |
| 1091 | } |
| 1092 | if (ref_e != NULL && new_e == NULL) { |
| 1093 | // args_count entities (argument adapters) are not found by heap traversal, |
| 1094 | // but they are not needed because they doesn't contain any code. |
| 1095 | ref_e = strchr(ref_e, ',') + 1; |
| 1096 | const char* args_count = "\"args_count:"; |
| 1097 | return IsStringEqualTo(args_count, ref_e); |
| 1098 | } |
| 1099 | return false; |
| 1100 | } |
| 1101 | |
| 1102 | |
| 1103 | // Test that logging of code create / move / delete events |
| 1104 | // is equivalent to traversal of a resulting heap. |
| 1105 | TEST(EquivalenceOfLoggingAndTraversal) { |
| 1106 | // This test needs to be run on a "clean" V8 to ensure that snapshot log |
| 1107 | // is loaded. This is always true when running using tools/test.py because |
| 1108 | // it launches a new cctest instance for every test. To be sure that launching |
| 1109 | // cctest manually also works, please be sure that no tests below |
| 1110 | // are using V8. |
| 1111 | // |
| 1112 | // P.S. No, V8 can't be re-initialized after disposal, see include/v8.h. |
| 1113 | CHECK(!i::V8::IsRunning()); |
| 1114 | |
| 1115 | i::FLAG_logfile = "*"; |
| 1116 | i::FLAG_log = true; |
| 1117 | i::FLAG_log_code = true; |
| 1118 | |
| 1119 | // Make sure objects move. |
| 1120 | bool saved_always_compact = i::FLAG_always_compact; |
| 1121 | if (!i::FLAG_never_compact) { |
| 1122 | i::FLAG_always_compact = true; |
| 1123 | } |
| 1124 | |
| 1125 | v8::HandleScope scope; |
| 1126 | v8::Handle<v8::Value> global_object = v8::Handle<v8::Value>(); |
| 1127 | v8::Handle<v8::Context> env = v8::Context::New( |
| 1128 | 0, v8::Handle<v8::ObjectTemplate>(), global_object); |
| 1129 | env->Enter(); |
| 1130 | |
| 1131 | // Compile and run a function that creates other functions. |
| 1132 | CompileAndRunScript( |
| 1133 | "(function f(obj) {\n" |
| 1134 | " obj.test =\n" |
| 1135 | " (function a(j) { return function b() { return j; } })(100);\n" |
| 1136 | "})(this);"); |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 1137 | HEAP->CollectAllGarbage(false); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 1138 | |
| 1139 | EmbeddedVector<char, 204800> buffer; |
| 1140 | int log_size; |
| 1141 | ParseLogResult ref_result; |
| 1142 | |
| 1143 | // Retrieve the log. |
| 1144 | { |
| 1145 | // Make sure that no GCs occur prior to LogCompiledFunctions call. |
| 1146 | i::AssertNoAllocation no_alloc; |
| 1147 | |
| 1148 | log_size = GetLogLines(0, &buffer); |
| 1149 | CHECK_GT(log_size, 0); |
| 1150 | CHECK_GT(buffer.length(), log_size); |
| 1151 | |
| 1152 | // Fill a map of compiled code objects. |
| 1153 | ParseLog(buffer.start(), buffer.start() + log_size, &ref_result); |
| 1154 | } |
| 1155 | |
| 1156 | // Iterate heap to find compiled functions, will write to log. |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 1157 | LOGGER->LogCompiledFunctions(); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 1158 | char* new_log_start = buffer.start() + log_size; |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 1159 | const int new_log_size = LOGGER->GetLogLines( |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 1160 | log_size, new_log_start, buffer.length() - log_size); |
| 1161 | CHECK_GT(new_log_size, 0); |
| 1162 | CHECK_GT(buffer.length(), log_size + new_log_size); |
| 1163 | |
| 1164 | // Fill an equivalent map of compiled code objects. |
| 1165 | ParseLogResult new_result; |
| 1166 | ParseLog(new_log_start, new_log_start + new_log_size, &new_result); |
| 1167 | |
| 1168 | // Test their actual equivalence. |
| 1169 | Interval combined; |
| 1170 | combined.CloneFrom(&ref_result.bounds); |
| 1171 | combined.CloneFrom(&new_result.bounds); |
| 1172 | Interval* iter = &combined; |
| 1173 | bool results_equal = true; |
| 1174 | |
| 1175 | while (iter != NULL) { |
| 1176 | for (Address addr = iter->raw_min_addr(); |
| 1177 | addr <= iter->raw_max_addr(); ++addr) { |
| 1178 | CodeEntityInfo ref_entity = ref_result.GetEntity(addr); |
| 1179 | CodeEntityInfo new_entity = new_result.GetEntity(addr); |
| 1180 | if (ref_entity != NULL || new_entity != NULL) { |
| 1181 | const bool equal = AreEntitiesEqual(ref_entity, new_entity); |
| 1182 | if (!equal) results_equal = false; |
| 1183 | PrintCodeEntitiesInfo(equal, addr, ref_entity, new_entity); |
| 1184 | } |
| 1185 | } |
| 1186 | iter = iter->get_next(); |
| 1187 | } |
| 1188 | // Make sure that all log data is written prior crash due to CHECK failure. |
| 1189 | fflush(stdout); |
| 1190 | CHECK(results_equal); |
| 1191 | |
| 1192 | env->Exit(); |
Steve Block | 44f0eee | 2011-05-26 01:26:41 +0100 | [diff] [blame^] | 1193 | LOGGER->TearDown(); |
Steve Block | a7e24c1 | 2009-10-30 11:49:00 +0000 | [diff] [blame] | 1194 | i::FLAG_always_compact = saved_always_compact; |
| 1195 | } |
| 1196 | |
| 1197 | #endif // ENABLE_LOGGING_AND_PROFILING |