| OLD | NEW |
| 1 // Copyright 2009 the V8 project authors. All rights reserved. | 1 // Copyright 2009 the V8 project authors. All rights reserved. |
| 2 // Redistribution and use in source and binary forms, with or without | 2 // Redistribution and use in source and binary forms, with or without |
| 3 // modification, are permitted provided that the following conditions are | 3 // modification, are permitted provided that the following conditions are |
| 4 // met: | 4 // met: |
| 5 // | 5 // |
| 6 // * Redistributions of source code must retain the above copyright | 6 // * Redistributions of source code must retain the above copyright |
| 7 // notice, this list of conditions and the following disclaimer. | 7 // notice, this list of conditions and the following disclaimer. |
| 8 // * Redistributions in binary form must reproduce the above | 8 // * Redistributions in binary form must reproduce the above |
| 9 // copyright notice, this list of conditions and the following | 9 // copyright notice, this list of conditions and the following |
| 10 // disclaimer in the documentation and/or other materials provided | 10 // disclaimer in the documentation and/or other materials provided |
| (...skipping 46 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 57 void AddState(StateTag state); | 57 void AddState(StateTag state); |
| 58 | 58 |
| 59 private: | 59 private: |
| 60 static const int kBufferSize = 256; | 60 static const int kBufferSize = 256; |
| 61 int current_index_; | 61 int current_index_; |
| 62 bool is_full_; | 62 bool is_full_; |
| 63 byte buffer_[kBufferSize]; | 63 byte buffer_[kBufferSize]; |
| 64 | 64 |
| 65 | 65 |
| 66 void IncrementStateCounter(StateTag state) { | 66 void IncrementStateCounter(StateTag state) { |
| 67 Counters::state_counters[state].Increment(); | 67 COUNTERS->state_counters(state)->Increment(); |
| 68 } | 68 } |
| 69 | 69 |
| 70 | 70 |
| 71 void DecrementStateCounter(StateTag state) { | 71 void DecrementStateCounter(StateTag state) { |
| 72 Counters::state_counters[state].Decrement(); | 72 COUNTERS->state_counters(state)->Decrement(); |
| 73 } | 73 } |
| 74 }; | 74 }; |
| 75 | 75 |
| 76 | 76 |
| 77 // | 77 // |
| 78 // The Profiler samples pc and sp values for the main thread. | 78 // The Profiler samples pc and sp values for the main thread. |
| 79 // Each sample is appended to a circular buffer. | 79 // Each sample is appended to a circular buffer. |
| 80 // An independent thread removes data and writes it to the log. | 80 // An independent thread removes data and writes it to the log. |
| 81 // This design minimizes the time spent in the sampler. | 81 // This design minimizes the time spent in the sampler. |
| 82 // | 82 // |
| 83 class Profiler: public Thread { | 83 class Profiler: public Thread { |
| 84 public: | 84 public: |
| 85 Profiler(); | 85 explicit Profiler(Isolate* isolate); |
| 86 void Engage(); | 86 void Engage(); |
| 87 void Disengage(); | 87 void Disengage(); |
| 88 | 88 |
| 89 // Inserts collected profiling data into buffer. | 89 // Inserts collected profiling data into buffer. |
| 90 void Insert(TickSample* sample) { | 90 void Insert(TickSample* sample) { |
| 91 if (paused_) | 91 if (paused_) |
| 92 return; | 92 return; |
| 93 | 93 |
| 94 if (Succ(head_) == tail_) { | 94 if (Succ(head_) == tail_) { |
| 95 overflow_ = true; | 95 overflow_ = true; |
| (...skipping 10 matching lines...) Expand all Loading... |
| 106 *sample = buffer_[tail_]; | 106 *sample = buffer_[tail_]; |
| 107 bool result = overflow_; | 107 bool result = overflow_; |
| 108 tail_ = Succ(tail_); | 108 tail_ = Succ(tail_); |
| 109 overflow_ = false; | 109 overflow_ = false; |
| 110 return result; | 110 return result; |
| 111 } | 111 } |
| 112 | 112 |
| 113 void Run(); | 113 void Run(); |
| 114 | 114 |
| 115 // Pause and Resume TickSample data collection. | 115 // Pause and Resume TickSample data collection. |
| 116 static bool paused() { return paused_; } | 116 bool paused() const { return paused_; } |
| 117 static void pause() { paused_ = true; } | 117 void pause() { paused_ = true; } |
| 118 static void resume() { paused_ = false; } | 118 void resume() { paused_ = false; } |
| 119 | 119 |
| 120 private: | 120 private: |
| 121 // Returns the next index in the cyclic buffer. | 121 // Returns the next index in the cyclic buffer. |
| 122 int Succ(int index) { return (index + 1) % kBufferSize; } | 122 int Succ(int index) { return (index + 1) % kBufferSize; } |
| 123 | 123 |
| 124 // Cyclic buffer for communicating profiling samples | 124 // Cyclic buffer for communicating profiling samples |
| 125 // between the signal handler and the worker thread. | 125 // between the signal handler and the worker thread. |
| 126 static const int kBufferSize = 128; | 126 static const int kBufferSize = 128; |
| 127 TickSample buffer_[kBufferSize]; // Buffer storage. | 127 TickSample buffer_[kBufferSize]; // Buffer storage. |
| 128 int head_; // Index to the buffer head. | 128 int head_; // Index to the buffer head. |
| 129 int tail_; // Index to the buffer tail. | 129 int tail_; // Index to the buffer tail. |
| 130 bool overflow_; // Tell whether a buffer overflow has occurred. | 130 bool overflow_; // Tell whether a buffer overflow has occurred. |
| 131 Semaphore* buffer_semaphore_; // Sempahore used for buffer synchronization. | 131 Semaphore* buffer_semaphore_; // Sempahore used for buffer synchronization. |
| 132 | 132 |
| 133 // Tells whether profiler is engaged, that is, processing thread is stated. | 133 // Tells whether profiler is engaged, that is, processing thread is stated. |
| 134 bool engaged_; | 134 bool engaged_; |
| 135 | 135 |
| 136 // Tells whether worker thread should continue running. | 136 // Tells whether worker thread should continue running. |
| 137 bool running_; | 137 bool running_; |
| 138 | 138 |
| 139 // Tells whether we are currently recording tick samples. | 139 // Tells whether we are currently recording tick samples. |
| 140 static bool paused_; | 140 bool paused_; |
| 141 }; | 141 }; |
| 142 | 142 |
| 143 bool Profiler::paused_ = false; | |
| 144 | |
| 145 | 143 |
| 146 // | 144 // |
| 147 // StackTracer implementation | 145 // StackTracer implementation |
| 148 // | 146 // |
| 149 void StackTracer::Trace(TickSample* sample) { | 147 void StackTracer::Trace(Isolate* isolate, TickSample* sample) { |
| 148 ASSERT(isolate->IsInitialized()); |
| 149 |
| 150 sample->tos = NULL; | 150 sample->tos = NULL; |
| 151 sample->frames_count = 0; | 151 sample->frames_count = 0; |
| 152 | 152 |
| 153 // Avoid collecting traces while doing GC. | 153 // Avoid collecting traces while doing GC. |
| 154 if (sample->state == GC) return; | 154 if (sample->state == GC) return; |
| 155 | 155 |
| 156 const Address js_entry_sp = Top::js_entry_sp(Top::GetCurrentThread()); | 156 const Address js_entry_sp = |
| 157 Isolate::js_entry_sp(isolate->thread_local_top()); |
| 157 if (js_entry_sp == 0) { | 158 if (js_entry_sp == 0) { |
| 158 // Not executing JS now. | 159 // Not executing JS now. |
| 159 return; | 160 return; |
| 160 } | 161 } |
| 161 | 162 |
| 162 // Sample potential return address value for frameless invocation of | 163 // Sample potential return address value for frameless invocation of |
| 163 // stubs (we'll figure out later, if this value makes sense). | 164 // stubs (we'll figure out later, if this value makes sense). |
| 164 sample->tos = Memory::Address_at(sample->sp); | 165 sample->tos = Memory::Address_at(sample->sp); |
| 165 | 166 |
| 166 int i = 0; | 167 int i = 0; |
| 167 const Address callback = Top::external_callback(); | 168 const Address callback = isolate->external_callback(); |
| 168 // Surprisingly, PC can point _exactly_ to callback start, with good | 169 // Surprisingly, PC can point _exactly_ to callback start, with good |
| 169 // probability, and this will result in reporting fake nested | 170 // probability, and this will result in reporting fake nested |
| 170 // callback call. | 171 // callback call. |
| 171 if (callback != NULL && callback != sample->pc) { | 172 if (callback != NULL && callback != sample->pc) { |
| 172 sample->stack[i++] = callback; | 173 sample->stack[i++] = callback; |
| 173 } | 174 } |
| 174 | 175 |
| 175 SafeStackTraceFrameIterator it(sample->fp, sample->sp, | 176 SafeStackTraceFrameIterator it(isolate, |
| 177 sample->fp, sample->sp, |
| 176 sample->sp, js_entry_sp); | 178 sample->sp, js_entry_sp); |
| 177 while (!it.done() && i < TickSample::kMaxFramesCount) { | 179 while (!it.done() && i < TickSample::kMaxFramesCount) { |
| 178 sample->stack[i++] = it.frame()->pc(); | 180 sample->stack[i++] = it.frame()->pc(); |
| 179 it.Advance(); | 181 it.Advance(); |
| 180 } | 182 } |
| 181 sample->frames_count = i; | 183 sample->frames_count = i; |
| 182 } | 184 } |
| 183 | 185 |
| 184 | 186 |
| 185 // | 187 // |
| 186 // Ticker used to provide ticks to the profiler and the sliding state | 188 // Ticker used to provide ticks to the profiler and the sliding state |
| 187 // window. | 189 // window. |
| 188 // | 190 // |
| 189 class Ticker: public Sampler { | 191 class Ticker: public Sampler { |
| 190 public: | 192 public: |
| 191 explicit Ticker(int interval) : | 193 explicit Ticker(Isolate* isolate, int interval): |
| 192 Sampler(interval), | 194 Sampler(isolate, interval), |
| 193 window_(NULL), | 195 window_(NULL), |
| 194 profiler_(NULL) {} | 196 profiler_(NULL) {} |
| 195 | 197 |
| 196 ~Ticker() { if (IsActive()) Stop(); } | 198 ~Ticker() { if (IsActive()) Stop(); } |
| 197 | 199 |
| 198 virtual void Tick(TickSample* sample) { | 200 virtual void Tick(TickSample* sample) { |
| 199 if (profiler_) profiler_->Insert(sample); | 201 if (profiler_) profiler_->Insert(sample); |
| 200 if (window_) window_->AddState(sample->state); | 202 if (window_) window_->AddState(sample->state); |
| 201 } | 203 } |
| 202 | 204 |
| (...skipping 15 matching lines...) Expand all Loading... |
| 218 } | 220 } |
| 219 | 221 |
| 220 void ClearProfiler() { | 222 void ClearProfiler() { |
| 221 DecreaseProfilingDepth(); | 223 DecreaseProfilingDepth(); |
| 222 profiler_ = NULL; | 224 profiler_ = NULL; |
| 223 if (!window_ && IsActive() && !RuntimeProfiler::IsEnabled()) Stop(); | 225 if (!window_ && IsActive() && !RuntimeProfiler::IsEnabled()) Stop(); |
| 224 } | 226 } |
| 225 | 227 |
| 226 protected: | 228 protected: |
| 227 virtual void DoSampleStack(TickSample* sample) { | 229 virtual void DoSampleStack(TickSample* sample) { |
| 228 StackTracer::Trace(sample); | 230 StackTracer::Trace(isolate(), sample); |
| 229 } | 231 } |
| 230 | 232 |
| 231 private: | 233 private: |
| 232 SlidingStateWindow* window_; | 234 SlidingStateWindow* window_; |
| 233 Profiler* profiler_; | 235 Profiler* profiler_; |
| 234 }; | 236 }; |
| 235 | 237 |
| 236 | 238 |
| 237 // | 239 // |
| 238 // SlidingStateWindow implementation. | 240 // SlidingStateWindow implementation. |
| 239 // | 241 // |
| 240 SlidingStateWindow::SlidingStateWindow(): current_index_(0), is_full_(false) { | 242 SlidingStateWindow::SlidingStateWindow(): current_index_(0), is_full_(false) { |
| 241 for (int i = 0; i < kBufferSize; i++) { | 243 for (int i = 0; i < kBufferSize; i++) { |
| 242 buffer_[i] = static_cast<byte>(OTHER); | 244 buffer_[i] = static_cast<byte>(OTHER); |
| 243 } | 245 } |
| 244 Logger::ticker_->SetWindow(this); | 246 LOGGER->ticker_->SetWindow(this); |
| 245 } | 247 } |
| 246 | 248 |
| 247 | 249 |
| 248 SlidingStateWindow::~SlidingStateWindow() { | 250 SlidingStateWindow::~SlidingStateWindow() { |
| 249 Logger::ticker_->ClearWindow(); | 251 LOGGER->ticker_->ClearWindow(); |
| 250 } | 252 } |
| 251 | 253 |
| 252 | 254 |
| 253 void SlidingStateWindow::AddState(StateTag state) { | 255 void SlidingStateWindow::AddState(StateTag state) { |
| 254 if (is_full_) { | 256 if (is_full_) { |
| 255 DecrementStateCounter(static_cast<StateTag>(buffer_[current_index_])); | 257 DecrementStateCounter(static_cast<StateTag>(buffer_[current_index_])); |
| 256 } else if (current_index_ == kBufferSize - 1) { | 258 } else if (current_index_ == kBufferSize - 1) { |
| 257 is_full_ = true; | 259 is_full_ = true; |
| 258 } | 260 } |
| 259 buffer_[current_index_] = static_cast<byte>(state); | 261 buffer_[current_index_] = static_cast<byte>(state); |
| 260 IncrementStateCounter(state); | 262 IncrementStateCounter(state); |
| 261 ASSERT(IsPowerOf2(kBufferSize)); | 263 ASSERT(IsPowerOf2(kBufferSize)); |
| 262 current_index_ = (current_index_ + 1) & (kBufferSize - 1); | 264 current_index_ = (current_index_ + 1) & (kBufferSize - 1); |
| 263 } | 265 } |
| 264 | 266 |
| 265 | 267 |
| 266 // | 268 // |
| 267 // Profiler implementation. | 269 // Profiler implementation. |
| 268 // | 270 // |
| 269 Profiler::Profiler() | 271 Profiler::Profiler(Isolate* isolate) |
| 270 : Thread("v8:Profiler"), | 272 : Thread(isolate, "v8:Profiler"), |
| 271 head_(0), | 273 head_(0), |
| 272 tail_(0), | 274 tail_(0), |
| 273 overflow_(false), | 275 overflow_(false), |
| 274 buffer_semaphore_(OS::CreateSemaphore(0)), | 276 buffer_semaphore_(OS::CreateSemaphore(0)), |
| 275 engaged_(false), | 277 engaged_(false), |
| 276 running_(false) { | 278 running_(false), |
| 279 paused_(false) { |
| 277 } | 280 } |
| 278 | 281 |
| 279 | 282 |
| 280 void Profiler::Engage() { | 283 void Profiler::Engage() { |
| 281 if (engaged_) return; | 284 if (engaged_) return; |
| 282 engaged_ = true; | 285 engaged_ = true; |
| 283 | 286 |
| 284 // TODO(mnaganov): This is actually "Chromium" mode. Flags need to be revised. | 287 // TODO(mnaganov): This is actually "Chromium" mode. Flags need to be revised. |
| 285 // http://code.google.com/p/v8/issues/detail?id=487 | 288 // http://code.google.com/p/v8/issues/detail?id=487 |
| 286 if (!FLAG_prof_lazy) { | 289 if (!FLAG_prof_lazy) { |
| 287 OS::LogSharedLibraryAddresses(); | 290 OS::LogSharedLibraryAddresses(); |
| 288 } | 291 } |
| 289 | 292 |
| 290 // Start thread processing the profiler buffer. | 293 // Start thread processing the profiler buffer. |
| 291 running_ = true; | 294 running_ = true; |
| 292 Start(); | 295 Start(); |
| 293 | 296 |
| 294 // Register to get ticks. | 297 // Register to get ticks. |
| 295 Logger::ticker_->SetProfiler(this); | 298 LOGGER->ticker_->SetProfiler(this); |
| 296 | 299 |
| 297 Logger::ProfilerBeginEvent(); | 300 LOGGER->ProfilerBeginEvent(); |
| 298 } | 301 } |
| 299 | 302 |
| 300 | 303 |
| 301 void Profiler::Disengage() { | 304 void Profiler::Disengage() { |
| 302 if (!engaged_) return; | 305 if (!engaged_) return; |
| 303 | 306 |
| 304 // Stop receiving ticks. | 307 // Stop receiving ticks. |
| 305 Logger::ticker_->ClearProfiler(); | 308 LOGGER->ticker_->ClearProfiler(); |
| 306 | 309 |
| 307 // Terminate the worker thread by setting running_ to false, | 310 // Terminate the worker thread by setting running_ to false, |
| 308 // inserting a fake element in the queue and then wait for | 311 // inserting a fake element in the queue and then wait for |
| 309 // the thread to terminate. | 312 // the thread to terminate. |
| 310 running_ = false; | 313 running_ = false; |
| 311 TickSample sample; | 314 TickSample sample; |
| 312 // Reset 'paused_' flag, otherwise semaphore may not be signalled. | 315 // Reset 'paused_' flag, otherwise semaphore may not be signalled. |
| 313 resume(); | 316 resume(); |
| 314 Insert(&sample); | 317 Insert(&sample); |
| 315 Join(); | 318 Join(); |
| 316 | 319 |
| 317 LOG(UncheckedStringEvent("profiler", "end")); | 320 LOG(ISOLATE, UncheckedStringEvent("profiler", "end")); |
| 318 } | 321 } |
| 319 | 322 |
| 320 | 323 |
| 321 void Profiler::Run() { | 324 void Profiler::Run() { |
| 322 TickSample sample; | 325 TickSample sample; |
| 323 bool overflow = Remove(&sample); | 326 bool overflow = Remove(&sample); |
| 327 i::Isolate* isolate = ISOLATE; |
| 324 while (running_) { | 328 while (running_) { |
| 325 LOG(TickEvent(&sample, overflow)); | 329 LOG(isolate, TickEvent(&sample, overflow)); |
| 326 overflow = Remove(&sample); | 330 overflow = Remove(&sample); |
| 327 } | 331 } |
| 328 } | 332 } |
| 329 | 333 |
| 330 | 334 |
| 331 // | 335 // |
| 332 // Logger class implementation. | 336 // Logger class implementation. |
| 333 // | 337 // |
| 334 Ticker* Logger::ticker_ = NULL; | 338 |
| 335 Profiler* Logger::profiler_ = NULL; | 339 Logger::Logger() |
| 336 SlidingStateWindow* Logger::sliding_state_window_ = NULL; | 340 : ticker_(NULL), |
| 337 int Logger::logging_nesting_ = 0; | 341 profiler_(NULL), |
| 338 int Logger::cpu_profiler_nesting_ = 0; | 342 sliding_state_window_(NULL), |
| 339 int Logger::heap_profiler_nesting_ = 0; | 343 log_events_(NULL), |
| 344 logging_nesting_(0), |
| 345 cpu_profiler_nesting_(0), |
| 346 heap_profiler_nesting_(0), |
| 347 log_(new Log(this)), |
| 348 is_initialized_(false), |
| 349 last_address_(NULL), |
| 350 prev_sp_(NULL), |
| 351 prev_function_(NULL), |
| 352 prev_to_(NULL), |
| 353 prev_code_(NULL) { |
| 354 } |
| 355 |
| 356 Logger::~Logger() { |
| 357 delete log_; |
| 358 } |
| 340 | 359 |
| 341 #define DECLARE_EVENT(ignore1, name) name, | 360 #define DECLARE_EVENT(ignore1, name) name, |
| 342 const char* kLogEventsNames[Logger::NUMBER_OF_LOG_EVENTS] = { | 361 static const char* const kLogEventsNames[Logger::NUMBER_OF_LOG_EVENTS] = { |
| 343 LOG_EVENTS_AND_TAGS_LIST(DECLARE_EVENT) | 362 LOG_EVENTS_AND_TAGS_LIST(DECLARE_EVENT) |
| 344 }; | 363 }; |
| 345 #undef DECLARE_EVENT | 364 #undef DECLARE_EVENT |
| 346 | 365 |
| 347 | 366 |
| 348 void Logger::ProfilerBeginEvent() { | 367 void Logger::ProfilerBeginEvent() { |
| 349 if (!Log::IsEnabled()) return; | 368 if (!log_->IsEnabled()) return; |
| 350 LogMessageBuilder msg; | 369 LogMessageBuilder msg(this); |
| 351 msg.Append("profiler,\"begin\",%d\n", kSamplingIntervalMs); | 370 msg.Append("profiler,\"begin\",%d\n", kSamplingIntervalMs); |
| 352 msg.WriteToLogFile(); | 371 msg.WriteToLogFile(); |
| 353 } | 372 } |
| 354 | 373 |
| 355 #endif // ENABLE_LOGGING_AND_PROFILING | 374 #endif // ENABLE_LOGGING_AND_PROFILING |
| 356 | 375 |
| 357 | 376 |
| 358 void Logger::StringEvent(const char* name, const char* value) { | 377 void Logger::StringEvent(const char* name, const char* value) { |
| 359 #ifdef ENABLE_LOGGING_AND_PROFILING | 378 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 360 if (FLAG_log) UncheckedStringEvent(name, value); | 379 if (FLAG_log) UncheckedStringEvent(name, value); |
| 361 #endif | 380 #endif |
| 362 } | 381 } |
| 363 | 382 |
| 364 | 383 |
| 365 #ifdef ENABLE_LOGGING_AND_PROFILING | 384 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 366 void Logger::UncheckedStringEvent(const char* name, const char* value) { | 385 void Logger::UncheckedStringEvent(const char* name, const char* value) { |
| 367 if (!Log::IsEnabled()) return; | 386 if (!log_->IsEnabled()) return; |
| 368 LogMessageBuilder msg; | 387 LogMessageBuilder msg(this); |
| 369 msg.Append("%s,\"%s\"\n", name, value); | 388 msg.Append("%s,\"%s\"\n", name, value); |
| 370 msg.WriteToLogFile(); | 389 msg.WriteToLogFile(); |
| 371 } | 390 } |
| 372 #endif | 391 #endif |
| 373 | 392 |
| 374 | 393 |
| 375 void Logger::IntEvent(const char* name, int value) { | 394 void Logger::IntEvent(const char* name, int value) { |
| 376 #ifdef ENABLE_LOGGING_AND_PROFILING | 395 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 377 if (FLAG_log) UncheckedIntEvent(name, value); | 396 if (FLAG_log) UncheckedIntEvent(name, value); |
| 378 #endif | 397 #endif |
| 379 } | 398 } |
| 380 | 399 |
| 381 | 400 |
| 382 void Logger::IntPtrTEvent(const char* name, intptr_t value) { | 401 void Logger::IntPtrTEvent(const char* name, intptr_t value) { |
| 383 #ifdef ENABLE_LOGGING_AND_PROFILING | 402 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 384 if (FLAG_log) UncheckedIntPtrTEvent(name, value); | 403 if (FLAG_log) UncheckedIntPtrTEvent(name, value); |
| 385 #endif | 404 #endif |
| 386 } | 405 } |
| 387 | 406 |
| 388 | 407 |
| 389 #ifdef ENABLE_LOGGING_AND_PROFILING | 408 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 390 void Logger::UncheckedIntEvent(const char* name, int value) { | 409 void Logger::UncheckedIntEvent(const char* name, int value) { |
| 391 if (!Log::IsEnabled()) return; | 410 if (!log_->IsEnabled()) return; |
| 392 LogMessageBuilder msg; | 411 LogMessageBuilder msg(this); |
| 393 msg.Append("%s,%d\n", name, value); | 412 msg.Append("%s,%d\n", name, value); |
| 394 msg.WriteToLogFile(); | 413 msg.WriteToLogFile(); |
| 395 } | 414 } |
| 396 #endif | 415 #endif |
| 397 | 416 |
| 398 | 417 |
| 399 #ifdef ENABLE_LOGGING_AND_PROFILING | 418 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 400 void Logger::UncheckedIntPtrTEvent(const char* name, intptr_t value) { | 419 void Logger::UncheckedIntPtrTEvent(const char* name, intptr_t value) { |
| 401 if (!Log::IsEnabled()) return; | 420 if (!log_->IsEnabled()) return; |
| 402 LogMessageBuilder msg; | 421 LogMessageBuilder msg(this); |
| 403 msg.Append("%s,%" V8_PTR_PREFIX "d\n", name, value); | 422 msg.Append("%s,%" V8_PTR_PREFIX "d\n", name, value); |
| 404 msg.WriteToLogFile(); | 423 msg.WriteToLogFile(); |
| 405 } | 424 } |
| 406 #endif | 425 #endif |
| 407 | 426 |
| 408 | 427 |
| 409 void Logger::HandleEvent(const char* name, Object** location) { | 428 void Logger::HandleEvent(const char* name, Object** location) { |
| 410 #ifdef ENABLE_LOGGING_AND_PROFILING | 429 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 411 if (!Log::IsEnabled() || !FLAG_log_handles) return; | 430 if (!log_->IsEnabled() || !FLAG_log_handles) return; |
| 412 LogMessageBuilder msg; | 431 LogMessageBuilder msg(this); |
| 413 msg.Append("%s,0x%" V8PRIxPTR "\n", name, location); | 432 msg.Append("%s,0x%" V8PRIxPTR "\n", name, location); |
| 414 msg.WriteToLogFile(); | 433 msg.WriteToLogFile(); |
| 415 #endif | 434 #endif |
| 416 } | 435 } |
| 417 | 436 |
| 418 | 437 |
| 419 #ifdef ENABLE_LOGGING_AND_PROFILING | 438 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 420 // ApiEvent is private so all the calls come from the Logger class. It is the | 439 // ApiEvent is private so all the calls come from the Logger class. It is the |
| 421 // caller's responsibility to ensure that log is enabled and that | 440 // caller's responsibility to ensure that log is enabled and that |
| 422 // FLAG_log_api is true. | 441 // FLAG_log_api is true. |
| 423 void Logger::ApiEvent(const char* format, ...) { | 442 void Logger::ApiEvent(const char* format, ...) { |
| 424 ASSERT(Log::IsEnabled() && FLAG_log_api); | 443 ASSERT(log_->IsEnabled() && FLAG_log_api); |
| 425 LogMessageBuilder msg; | 444 LogMessageBuilder msg(this); |
| 426 va_list ap; | 445 va_list ap; |
| 427 va_start(ap, format); | 446 va_start(ap, format); |
| 428 msg.AppendVA(format, ap); | 447 msg.AppendVA(format, ap); |
| 429 va_end(ap); | 448 va_end(ap); |
| 430 msg.WriteToLogFile(); | 449 msg.WriteToLogFile(); |
| 431 } | 450 } |
| 432 #endif | 451 #endif |
| 433 | 452 |
| 434 | 453 |
| 435 void Logger::ApiNamedSecurityCheck(Object* key) { | 454 void Logger::ApiNamedSecurityCheck(Object* key) { |
| 436 #ifdef ENABLE_LOGGING_AND_PROFILING | 455 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 437 if (!Log::IsEnabled() || !FLAG_log_api) return; | 456 if (!log_->IsEnabled() || !FLAG_log_api) return; |
| 438 if (key->IsString()) { | 457 if (key->IsString()) { |
| 439 SmartPointer<char> str = | 458 SmartPointer<char> str = |
| 440 String::cast(key)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); | 459 String::cast(key)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); |
| 441 ApiEvent("api,check-security,\"%s\"\n", *str); | 460 ApiEvent("api,check-security,\"%s\"\n", *str); |
| 442 } else if (key->IsUndefined()) { | 461 } else if (key->IsUndefined()) { |
| 443 ApiEvent("api,check-security,undefined\n"); | 462 ApiEvent("api,check-security,undefined\n"); |
| 444 } else { | 463 } else { |
| 445 ApiEvent("api,check-security,['no-name']\n"); | 464 ApiEvent("api,check-security,['no-name']\n"); |
| 446 } | 465 } |
| 447 #endif | 466 #endif |
| 448 } | 467 } |
| 449 | 468 |
| 450 | 469 |
| 451 void Logger::SharedLibraryEvent(const char* library_path, | 470 void Logger::SharedLibraryEvent(const char* library_path, |
| 452 uintptr_t start, | 471 uintptr_t start, |
| 453 uintptr_t end) { | 472 uintptr_t end) { |
| 454 #ifdef ENABLE_LOGGING_AND_PROFILING | 473 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 455 if (!Log::IsEnabled() || !FLAG_prof) return; | 474 if (!log_->IsEnabled() || !FLAG_prof) return; |
| 456 LogMessageBuilder msg; | 475 LogMessageBuilder msg(this); |
| 457 msg.Append("shared-library,\"%s\",0x%08" V8PRIxPTR ",0x%08" V8PRIxPTR "\n", | 476 msg.Append("shared-library,\"%s\",0x%08" V8PRIxPTR ",0x%08" V8PRIxPTR "\n", |
| 458 library_path, | 477 library_path, |
| 459 start, | 478 start, |
| 460 end); | 479 end); |
| 461 msg.WriteToLogFile(); | 480 msg.WriteToLogFile(); |
| 462 #endif | 481 #endif |
| 463 } | 482 } |
| 464 | 483 |
| 465 | 484 |
| 466 void Logger::SharedLibraryEvent(const wchar_t* library_path, | 485 void Logger::SharedLibraryEvent(const wchar_t* library_path, |
| 467 uintptr_t start, | 486 uintptr_t start, |
| 468 uintptr_t end) { | 487 uintptr_t end) { |
| 469 #ifdef ENABLE_LOGGING_AND_PROFILING | 488 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 470 if (!Log::IsEnabled() || !FLAG_prof) return; | 489 if (!log_->IsEnabled() || !FLAG_prof) return; |
| 471 LogMessageBuilder msg; | 490 LogMessageBuilder msg(this); |
| 472 msg.Append("shared-library,\"%ls\",0x%08" V8PRIxPTR ",0x%08" V8PRIxPTR "\n", | 491 msg.Append("shared-library,\"%ls\",0x%08" V8PRIxPTR ",0x%08" V8PRIxPTR "\n", |
| 473 library_path, | 492 library_path, |
| 474 start, | 493 start, |
| 475 end); | 494 end); |
| 476 msg.WriteToLogFile(); | 495 msg.WriteToLogFile(); |
| 477 #endif | 496 #endif |
| 478 } | 497 } |
| 479 | 498 |
| 480 | 499 |
| 481 #ifdef ENABLE_LOGGING_AND_PROFILING | 500 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 482 void Logger::LogRegExpSource(Handle<JSRegExp> regexp) { | 501 void Logger::LogRegExpSource(Handle<JSRegExp> regexp) { |
| 483 // Prints "/" + re.source + "/" + | 502 // Prints "/" + re.source + "/" + |
| 484 // (re.global?"g":"") + (re.ignorecase?"i":"") + (re.multiline?"m":"") | 503 // (re.global?"g":"") + (re.ignorecase?"i":"") + (re.multiline?"m":"") |
| 485 LogMessageBuilder msg; | 504 LogMessageBuilder msg(this); |
| 486 | 505 |
| 487 Handle<Object> source = GetProperty(regexp, "source"); | 506 Handle<Object> source = GetProperty(regexp, "source"); |
| 488 if (!source->IsString()) { | 507 if (!source->IsString()) { |
| 489 msg.Append("no source"); | 508 msg.Append("no source"); |
| 490 return; | 509 return; |
| 491 } | 510 } |
| 492 | 511 |
| 493 switch (regexp->TypeTag()) { | 512 switch (regexp->TypeTag()) { |
| 494 case JSRegExp::ATOM: | 513 case JSRegExp::ATOM: |
| 495 msg.Append('a'); | 514 msg.Append('a'); |
| (...skipping 21 matching lines...) Expand all Loading... |
| 517 msg.Append('m'); | 536 msg.Append('m'); |
| 518 } | 537 } |
| 519 | 538 |
| 520 msg.WriteToLogFile(); | 539 msg.WriteToLogFile(); |
| 521 } | 540 } |
| 522 #endif // ENABLE_LOGGING_AND_PROFILING | 541 #endif // ENABLE_LOGGING_AND_PROFILING |
| 523 | 542 |
| 524 | 543 |
| 525 void Logger::RegExpCompileEvent(Handle<JSRegExp> regexp, bool in_cache) { | 544 void Logger::RegExpCompileEvent(Handle<JSRegExp> regexp, bool in_cache) { |
| 526 #ifdef ENABLE_LOGGING_AND_PROFILING | 545 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 527 if (!Log::IsEnabled() || !FLAG_log_regexp) return; | 546 if (!log_->IsEnabled() || !FLAG_log_regexp) return; |
| 528 LogMessageBuilder msg; | 547 LogMessageBuilder msg(this); |
| 529 msg.Append("regexp-compile,"); | 548 msg.Append("regexp-compile,"); |
| 530 LogRegExpSource(regexp); | 549 LogRegExpSource(regexp); |
| 531 msg.Append(in_cache ? ",hit\n" : ",miss\n"); | 550 msg.Append(in_cache ? ",hit\n" : ",miss\n"); |
| 532 msg.WriteToLogFile(); | 551 msg.WriteToLogFile(); |
| 533 #endif | 552 #endif |
| 534 } | 553 } |
| 535 | 554 |
| 536 | 555 |
| 537 void Logger::LogRuntime(Vector<const char> format, JSArray* args) { | 556 void Logger::LogRuntime(Vector<const char> format, JSArray* args) { |
| 538 #ifdef ENABLE_LOGGING_AND_PROFILING | 557 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 539 if (!Log::IsEnabled() || !FLAG_log_runtime) return; | 558 if (!log_->IsEnabled() || !FLAG_log_runtime) return; |
| 540 HandleScope scope; | 559 HandleScope scope; |
| 541 LogMessageBuilder msg; | 560 LogMessageBuilder msg(this); |
| 542 for (int i = 0; i < format.length(); i++) { | 561 for (int i = 0; i < format.length(); i++) { |
| 543 char c = format[i]; | 562 char c = format[i]; |
| 544 if (c == '%' && i <= format.length() - 2) { | 563 if (c == '%' && i <= format.length() - 2) { |
| 545 i++; | 564 i++; |
| 546 ASSERT('0' <= format[i] && format[i] <= '9'); | 565 ASSERT('0' <= format[i] && format[i] <= '9'); |
| 547 MaybeObject* maybe = args->GetElement(format[i] - '0'); | 566 MaybeObject* maybe = args->GetElement(format[i] - '0'); |
| 548 Object* obj; | 567 Object* obj; |
| 549 if (!maybe->ToObject(&obj)) { | 568 if (!maybe->ToObject(&obj)) { |
| 550 msg.Append("<exception>"); | 569 msg.Append("<exception>"); |
| 551 continue; | 570 continue; |
| (...skipping 23 matching lines...) Expand all Loading... |
| 575 } | 594 } |
| 576 } | 595 } |
| 577 msg.Append('\n'); | 596 msg.Append('\n'); |
| 578 msg.WriteToLogFile(); | 597 msg.WriteToLogFile(); |
| 579 #endif | 598 #endif |
| 580 } | 599 } |
| 581 | 600 |
| 582 | 601 |
| 583 void Logger::ApiIndexedSecurityCheck(uint32_t index) { | 602 void Logger::ApiIndexedSecurityCheck(uint32_t index) { |
| 584 #ifdef ENABLE_LOGGING_AND_PROFILING | 603 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 585 if (!Log::IsEnabled() || !FLAG_log_api) return; | 604 if (!log_->IsEnabled() || !FLAG_log_api) return; |
| 586 ApiEvent("api,check-security,%u\n", index); | 605 ApiEvent("api,check-security,%u\n", index); |
| 587 #endif | 606 #endif |
| 588 } | 607 } |
| 589 | 608 |
| 590 | 609 |
| 591 void Logger::ApiNamedPropertyAccess(const char* tag, | 610 void Logger::ApiNamedPropertyAccess(const char* tag, |
| 592 JSObject* holder, | 611 JSObject* holder, |
| 593 Object* name) { | 612 Object* name) { |
| 594 #ifdef ENABLE_LOGGING_AND_PROFILING | 613 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 595 ASSERT(name->IsString()); | 614 ASSERT(name->IsString()); |
| 596 if (!Log::IsEnabled() || !FLAG_log_api) return; | 615 if (!log_->IsEnabled() || !FLAG_log_api) return; |
| 597 String* class_name_obj = holder->class_name(); | 616 String* class_name_obj = holder->class_name(); |
| 598 SmartPointer<char> class_name = | 617 SmartPointer<char> class_name = |
| 599 class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); | 618 class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); |
| 600 SmartPointer<char> property_name = | 619 SmartPointer<char> property_name = |
| 601 String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); | 620 String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); |
| 602 Logger::ApiEvent("api,%s,\"%s\",\"%s\"\n", tag, *class_name, *property_name); | 621 LOGGER->ApiEvent("api,%s,\"%s\",\"%s\"\n", tag, *class_name, *property_name); |
| 603 #endif | 622 #endif |
| 604 } | 623 } |
| 605 | 624 |
| 606 void Logger::ApiIndexedPropertyAccess(const char* tag, | 625 void Logger::ApiIndexedPropertyAccess(const char* tag, |
| 607 JSObject* holder, | 626 JSObject* holder, |
| 608 uint32_t index) { | 627 uint32_t index) { |
| 609 #ifdef ENABLE_LOGGING_AND_PROFILING | 628 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 610 if (!Log::IsEnabled() || !FLAG_log_api) return; | 629 if (!log_->IsEnabled() || !FLAG_log_api) return; |
| 611 String* class_name_obj = holder->class_name(); | 630 String* class_name_obj = holder->class_name(); |
| 612 SmartPointer<char> class_name = | 631 SmartPointer<char> class_name = |
| 613 class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); | 632 class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); |
| 614 Logger::ApiEvent("api,%s,\"%s\",%u\n", tag, *class_name, index); | 633 LOGGER->ApiEvent("api,%s,\"%s\",%u\n", tag, *class_name, index); |
| 615 #endif | 634 #endif |
| 616 } | 635 } |
| 617 | 636 |
| 618 void Logger::ApiObjectAccess(const char* tag, JSObject* object) { | 637 void Logger::ApiObjectAccess(const char* tag, JSObject* object) { |
| 619 #ifdef ENABLE_LOGGING_AND_PROFILING | 638 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 620 if (!Log::IsEnabled() || !FLAG_log_api) return; | 639 if (!log_->IsEnabled() || !FLAG_log_api) return; |
| 621 String* class_name_obj = object->class_name(); | 640 String* class_name_obj = object->class_name(); |
| 622 SmartPointer<char> class_name = | 641 SmartPointer<char> class_name = |
| 623 class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); | 642 class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); |
| 624 Logger::ApiEvent("api,%s,\"%s\"\n", tag, *class_name); | 643 LOGGER->ApiEvent("api,%s,\"%s\"\n", tag, *class_name); |
| 625 #endif | 644 #endif |
| 626 } | 645 } |
| 627 | 646 |
| 628 | 647 |
| 629 void Logger::ApiEntryCall(const char* name) { | 648 void Logger::ApiEntryCall(const char* name) { |
| 630 #ifdef ENABLE_LOGGING_AND_PROFILING | 649 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 631 if (!Log::IsEnabled() || !FLAG_log_api) return; | 650 if (!log_->IsEnabled() || !FLAG_log_api) return; |
| 632 Logger::ApiEvent("api,%s\n", name); | 651 LOGGER->ApiEvent("api,%s\n", name); |
| 633 #endif | 652 #endif |
| 634 } | 653 } |
| 635 | 654 |
| 636 | 655 |
| 637 void Logger::NewEvent(const char* name, void* object, size_t size) { | 656 void Logger::NewEvent(const char* name, void* object, size_t size) { |
| 638 #ifdef ENABLE_LOGGING_AND_PROFILING | 657 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 639 if (!Log::IsEnabled() || !FLAG_log) return; | 658 if (!log_->IsEnabled() || !FLAG_log) return; |
| 640 LogMessageBuilder msg; | 659 LogMessageBuilder msg(this); |
| 641 msg.Append("new,%s,0x%" V8PRIxPTR ",%u\n", name, object, | 660 msg.Append("new,%s,0x%" V8PRIxPTR ",%u\n", name, object, |
| 642 static_cast<unsigned int>(size)); | 661 static_cast<unsigned int>(size)); |
| 643 msg.WriteToLogFile(); | 662 msg.WriteToLogFile(); |
| 644 #endif | 663 #endif |
| 645 } | 664 } |
| 646 | 665 |
| 647 | 666 |
| 648 void Logger::DeleteEvent(const char* name, void* object) { | 667 void Logger::DeleteEvent(const char* name, void* object) { |
| 649 #ifdef ENABLE_LOGGING_AND_PROFILING | 668 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 650 if (!Log::IsEnabled() || !FLAG_log) return; | 669 if (!log_->IsEnabled() || !FLAG_log) return; |
| 651 LogMessageBuilder msg; | 670 LogMessageBuilder msg(this); |
| 652 msg.Append("delete,%s,0x%" V8PRIxPTR "\n", name, object); | 671 msg.Append("delete,%s,0x%" V8PRIxPTR "\n", name, object); |
| 653 msg.WriteToLogFile(); | 672 msg.WriteToLogFile(); |
| 654 #endif | 673 #endif |
| 655 } | 674 } |
| 656 | 675 |
| 657 | 676 |
| 677 void Logger::NewEventStatic(const char* name, void* object, size_t size) { |
| 678 LOGGER->NewEvent(name, object, size); |
| 679 } |
| 680 |
| 681 |
| 682 void Logger::DeleteEventStatic(const char* name, void* object) { |
| 683 LOGGER->DeleteEvent(name, object); |
| 684 } |
| 685 |
| 658 #ifdef ENABLE_LOGGING_AND_PROFILING | 686 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 659 void Logger::CallbackEventInternal(const char* prefix, const char* name, | 687 void Logger::CallbackEventInternal(const char* prefix, const char* name, |
| 660 Address entry_point) { | 688 Address entry_point) { |
| 661 if (!Log::IsEnabled() || !FLAG_log_code) return; | 689 if (!log_->IsEnabled() || !FLAG_log_code) return; |
| 662 LogMessageBuilder msg; | 690 LogMessageBuilder msg(this); |
| 663 msg.Append("%s,%s,", | 691 msg.Append("%s,%s,", |
| 664 kLogEventsNames[CODE_CREATION_EVENT], | 692 kLogEventsNames[CODE_CREATION_EVENT], |
| 665 kLogEventsNames[CALLBACK_TAG]); | 693 kLogEventsNames[CALLBACK_TAG]); |
| 666 msg.AppendAddress(entry_point); | 694 msg.AppendAddress(entry_point); |
| 667 msg.Append(",1,\"%s%s\"", prefix, name); | 695 msg.Append(",1,\"%s%s\"", prefix, name); |
| 668 msg.Append('\n'); | 696 msg.Append('\n'); |
| 669 msg.WriteToLogFile(); | 697 msg.WriteToLogFile(); |
| 670 } | 698 } |
| 671 #endif | 699 #endif |
| 672 | 700 |
| 673 | 701 |
| 674 void Logger::CallbackEvent(String* name, Address entry_point) { | 702 void Logger::CallbackEvent(String* name, Address entry_point) { |
| 675 #ifdef ENABLE_LOGGING_AND_PROFILING | 703 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 676 if (!Log::IsEnabled() || !FLAG_log_code) return; | 704 if (!log_->IsEnabled() || !FLAG_log_code) return; |
| 677 SmartPointer<char> str = | 705 SmartPointer<char> str = |
| 678 name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); | 706 name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); |
| 679 CallbackEventInternal("", *str, entry_point); | 707 CallbackEventInternal("", *str, entry_point); |
| 680 #endif | 708 #endif |
| 681 } | 709 } |
| 682 | 710 |
| 683 | 711 |
| 684 void Logger::GetterCallbackEvent(String* name, Address entry_point) { | 712 void Logger::GetterCallbackEvent(String* name, Address entry_point) { |
| 685 #ifdef ENABLE_LOGGING_AND_PROFILING | 713 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 686 if (!Log::IsEnabled() || !FLAG_log_code) return; | 714 if (!log_->IsEnabled() || !FLAG_log_code) return; |
| 687 SmartPointer<char> str = | 715 SmartPointer<char> str = |
| 688 name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); | 716 name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); |
| 689 CallbackEventInternal("get ", *str, entry_point); | 717 CallbackEventInternal("get ", *str, entry_point); |
| 690 #endif | 718 #endif |
| 691 } | 719 } |
| 692 | 720 |
| 693 | 721 |
| 694 void Logger::SetterCallbackEvent(String* name, Address entry_point) { | 722 void Logger::SetterCallbackEvent(String* name, Address entry_point) { |
| 695 #ifdef ENABLE_LOGGING_AND_PROFILING | 723 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 696 if (!Log::IsEnabled() || !FLAG_log_code) return; | 724 if (!log_->IsEnabled() || !FLAG_log_code) return; |
| 697 SmartPointer<char> str = | 725 SmartPointer<char> str = |
| 698 name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); | 726 name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); |
| 699 CallbackEventInternal("set ", *str, entry_point); | 727 CallbackEventInternal("set ", *str, entry_point); |
| 700 #endif | 728 #endif |
| 701 } | 729 } |
| 702 | 730 |
| 703 | 731 |
| 704 void Logger::CodeCreateEvent(LogEventsAndTags tag, | 732 void Logger::CodeCreateEvent(LogEventsAndTags tag, |
| 705 Code* code, | 733 Code* code, |
| 706 const char* comment) { | 734 const char* comment) { |
| 707 #ifdef ENABLE_LOGGING_AND_PROFILING | 735 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 708 if (!Log::IsEnabled() || !FLAG_log_code) return; | 736 if (!log_->IsEnabled() || !FLAG_log_code) return; |
| 709 LogMessageBuilder msg; | 737 LogMessageBuilder msg(this); |
| 710 msg.Append("%s,%s,", | 738 msg.Append("%s,%s,", |
| 711 kLogEventsNames[CODE_CREATION_EVENT], | 739 kLogEventsNames[CODE_CREATION_EVENT], |
| 712 kLogEventsNames[tag]); | 740 kLogEventsNames[tag]); |
| 713 msg.AppendAddress(code->address()); | 741 msg.AppendAddress(code->address()); |
| 714 msg.Append(",%d,\"", code->ExecutableSize()); | 742 msg.Append(",%d,\"", code->ExecutableSize()); |
| 715 for (const char* p = comment; *p != '\0'; p++) { | 743 for (const char* p = comment; *p != '\0'; p++) { |
| 716 if (*p == '"') { | 744 if (*p == '"') { |
| 717 msg.Append('\\'); | 745 msg.Append('\\'); |
| 718 } | 746 } |
| 719 msg.Append(*p); | 747 msg.Append(*p); |
| (...skipping 31 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 751 } | 779 } |
| 752 } | 780 } |
| 753 #endif | 781 #endif |
| 754 | 782 |
| 755 | 783 |
| 756 void Logger::CodeCreateEvent(LogEventsAndTags tag, | 784 void Logger::CodeCreateEvent(LogEventsAndTags tag, |
| 757 Code* code, | 785 Code* code, |
| 758 SharedFunctionInfo* shared, | 786 SharedFunctionInfo* shared, |
| 759 String* name) { | 787 String* name) { |
| 760 #ifdef ENABLE_LOGGING_AND_PROFILING | 788 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 761 if (!Log::IsEnabled() || !FLAG_log_code) return; | 789 if (!log_->IsEnabled() || !FLAG_log_code) return; |
| 762 if (code == Builtins::builtin(Builtins::LazyCompile)) return; | 790 if (code == Isolate::Current()->builtins()->builtin( |
| 763 LogMessageBuilder msg; | 791 Builtins::LazyCompile)) |
| 792 return; |
| 793 |
| 794 LogMessageBuilder msg(this); |
| 764 SmartPointer<char> str = | 795 SmartPointer<char> str = |
| 765 name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); | 796 name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); |
| 766 msg.Append("%s,%s,", | 797 msg.Append("%s,%s,", |
| 767 kLogEventsNames[CODE_CREATION_EVENT], | 798 kLogEventsNames[CODE_CREATION_EVENT], |
| 768 kLogEventsNames[tag]); | 799 kLogEventsNames[tag]); |
| 769 msg.AppendAddress(code->address()); | 800 msg.AppendAddress(code->address()); |
| 770 msg.Append(",%d,\"%s\",", code->ExecutableSize(), *str); | 801 msg.Append(",%d,\"%s\",", code->ExecutableSize(), *str); |
| 771 msg.AppendAddress(shared->address()); | 802 msg.AppendAddress(shared->address()); |
| 772 msg.Append(",%s", ComputeMarker(code)); | 803 msg.Append(",%s", ComputeMarker(code)); |
| 773 LowLevelCodeCreateEvent(code, &msg); | 804 LowLevelCodeCreateEvent(code, &msg); |
| 774 msg.Append('\n'); | 805 msg.Append('\n'); |
| 775 msg.WriteToLogFile(); | 806 msg.WriteToLogFile(); |
| 776 #endif | 807 #endif |
| 777 } | 808 } |
| 778 | 809 |
| 779 | 810 |
| 780 // Although, it is possible to extract source and line from | 811 // Although, it is possible to extract source and line from |
| 781 // the SharedFunctionInfo object, we left it to caller | 812 // the SharedFunctionInfo object, we left it to caller |
| 782 // to leave logging functions free from heap allocations. | 813 // to leave logging functions free from heap allocations. |
| 783 void Logger::CodeCreateEvent(LogEventsAndTags tag, | 814 void Logger::CodeCreateEvent(LogEventsAndTags tag, |
| 784 Code* code, | 815 Code* code, |
| 785 SharedFunctionInfo* shared, | 816 SharedFunctionInfo* shared, |
| 786 String* source, int line) { | 817 String* source, int line) { |
| 787 #ifdef ENABLE_LOGGING_AND_PROFILING | 818 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 788 if (!Log::IsEnabled() || !FLAG_log_code) return; | 819 if (!log_->IsEnabled() || !FLAG_log_code) return; |
| 789 LogMessageBuilder msg; | 820 LogMessageBuilder msg(this); |
| 790 SmartPointer<char> name = | 821 SmartPointer<char> name = |
| 791 shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); | 822 shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); |
| 792 SmartPointer<char> sourcestr = | 823 SmartPointer<char> sourcestr = |
| 793 source->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); | 824 source->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); |
| 794 msg.Append("%s,%s,", | 825 msg.Append("%s,%s,", |
| 795 kLogEventsNames[CODE_CREATION_EVENT], | 826 kLogEventsNames[CODE_CREATION_EVENT], |
| 796 kLogEventsNames[tag]); | 827 kLogEventsNames[tag]); |
| 797 msg.AppendAddress(code->address()); | 828 msg.AppendAddress(code->address()); |
| 798 msg.Append(",%d,\"%s %s:%d\",", | 829 msg.Append(",%d,\"%s %s:%d\",", |
| 799 code->ExecutableSize(), | 830 code->ExecutableSize(), |
| 800 *name, | 831 *name, |
| 801 *sourcestr, | 832 *sourcestr, |
| 802 line); | 833 line); |
| 803 msg.AppendAddress(shared->address()); | 834 msg.AppendAddress(shared->address()); |
| 804 msg.Append(",%s", ComputeMarker(code)); | 835 msg.Append(",%s", ComputeMarker(code)); |
| 805 LowLevelCodeCreateEvent(code, &msg); | 836 LowLevelCodeCreateEvent(code, &msg); |
| 806 msg.Append('\n'); | 837 msg.Append('\n'); |
| 807 msg.WriteToLogFile(); | 838 msg.WriteToLogFile(); |
| 808 #endif | 839 #endif |
| 809 } | 840 } |
| 810 | 841 |
| 811 | 842 |
| 812 void Logger::CodeCreateEvent(LogEventsAndTags tag, Code* code, int args_count) { | 843 void Logger::CodeCreateEvent(LogEventsAndTags tag, Code* code, int args_count) { |
| 813 #ifdef ENABLE_LOGGING_AND_PROFILING | 844 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 814 if (!Log::IsEnabled() || !FLAG_log_code) return; | 845 if (!log_->IsEnabled() || !FLAG_log_code) return; |
| 815 LogMessageBuilder msg; | 846 LogMessageBuilder msg(this); |
| 816 msg.Append("%s,%s,", | 847 msg.Append("%s,%s,", |
| 817 kLogEventsNames[CODE_CREATION_EVENT], | 848 kLogEventsNames[CODE_CREATION_EVENT], |
| 818 kLogEventsNames[tag]); | 849 kLogEventsNames[tag]); |
| 819 msg.AppendAddress(code->address()); | 850 msg.AppendAddress(code->address()); |
| 820 msg.Append(",%d,\"args_count: %d\"", code->ExecutableSize(), args_count); | 851 msg.Append(",%d,\"args_count: %d\"", code->ExecutableSize(), args_count); |
| 821 LowLevelCodeCreateEvent(code, &msg); | 852 LowLevelCodeCreateEvent(code, &msg); |
| 822 msg.Append('\n'); | 853 msg.Append('\n'); |
| 823 msg.WriteToLogFile(); | 854 msg.WriteToLogFile(); |
| 824 #endif | 855 #endif |
| 825 } | 856 } |
| 826 | 857 |
| 827 | 858 |
| 828 void Logger::CodeMovingGCEvent() { | 859 void Logger::CodeMovingGCEvent() { |
| 829 #ifdef ENABLE_LOGGING_AND_PROFILING | 860 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 830 if (!Log::IsEnabled() || !FLAG_log_code || !FLAG_ll_prof) return; | 861 if (!log_->IsEnabled() || !FLAG_log_code || !FLAG_ll_prof) return; |
| 831 LogMessageBuilder msg; | 862 LogMessageBuilder msg(this); |
| 832 msg.Append("%s\n", kLogEventsNames[CODE_MOVING_GC]); | 863 msg.Append("%s\n", kLogEventsNames[CODE_MOVING_GC]); |
| 833 msg.WriteToLogFile(); | 864 msg.WriteToLogFile(); |
| 834 OS::SignalCodeMovingGC(); | 865 OS::SignalCodeMovingGC(); |
| 835 #endif | 866 #endif |
| 836 } | 867 } |
| 837 | 868 |
| 838 | 869 |
| 839 void Logger::RegExpCodeCreateEvent(Code* code, String* source) { | 870 void Logger::RegExpCodeCreateEvent(Code* code, String* source) { |
| 840 #ifdef ENABLE_LOGGING_AND_PROFILING | 871 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 841 if (!Log::IsEnabled() || !FLAG_log_code) return; | 872 if (!log_->IsEnabled() || !FLAG_log_code) return; |
| 842 LogMessageBuilder msg; | 873 LogMessageBuilder msg(this); |
| 843 msg.Append("%s,%s,", | 874 msg.Append("%s,%s,", |
| 844 kLogEventsNames[CODE_CREATION_EVENT], | 875 kLogEventsNames[CODE_CREATION_EVENT], |
| 845 kLogEventsNames[REG_EXP_TAG]); | 876 kLogEventsNames[REG_EXP_TAG]); |
| 846 msg.AppendAddress(code->address()); | 877 msg.AppendAddress(code->address()); |
| 847 msg.Append(",%d,\"", code->ExecutableSize()); | 878 msg.Append(",%d,\"", code->ExecutableSize()); |
| 848 msg.AppendDetailed(source, false); | 879 msg.AppendDetailed(source, false); |
| 849 msg.Append('\"'); | 880 msg.Append('\"'); |
| 850 LowLevelCodeCreateEvent(code, &msg); | 881 LowLevelCodeCreateEvent(code, &msg); |
| 851 msg.Append('\n'); | 882 msg.Append('\n'); |
| 852 msg.WriteToLogFile(); | 883 msg.WriteToLogFile(); |
| (...skipping 10 matching lines...) Expand all Loading... |
| 863 | 894 |
| 864 void Logger::CodeDeleteEvent(Address from) { | 895 void Logger::CodeDeleteEvent(Address from) { |
| 865 #ifdef ENABLE_LOGGING_AND_PROFILING | 896 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 866 DeleteEventInternal(CODE_DELETE_EVENT, from); | 897 DeleteEventInternal(CODE_DELETE_EVENT, from); |
| 867 #endif | 898 #endif |
| 868 } | 899 } |
| 869 | 900 |
| 870 | 901 |
| 871 void Logger::SnapshotPositionEvent(Address addr, int pos) { | 902 void Logger::SnapshotPositionEvent(Address addr, int pos) { |
| 872 #ifdef ENABLE_LOGGING_AND_PROFILING | 903 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 873 if (!Log::IsEnabled() || !FLAG_log_snapshot_positions) return; | 904 if (!log_->IsEnabled() || !FLAG_log_snapshot_positions) return; |
| 874 LogMessageBuilder msg; | 905 LogMessageBuilder msg(this); |
| 875 msg.Append("%s,", kLogEventsNames[SNAPSHOT_POSITION_EVENT]); | 906 msg.Append("%s,", kLogEventsNames[SNAPSHOT_POSITION_EVENT]); |
| 876 msg.AppendAddress(addr); | 907 msg.AppendAddress(addr); |
| 877 msg.Append(",%d", pos); | 908 msg.Append(",%d", pos); |
| 878 msg.Append('\n'); | 909 msg.Append('\n'); |
| 879 msg.WriteToLogFile(); | 910 msg.WriteToLogFile(); |
| 880 #endif | 911 #endif |
| 881 } | 912 } |
| 882 | 913 |
| 883 | 914 |
| 884 void Logger::SharedFunctionInfoMoveEvent(Address from, Address to) { | 915 void Logger::SharedFunctionInfoMoveEvent(Address from, Address to) { |
| 885 #ifdef ENABLE_LOGGING_AND_PROFILING | 916 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 886 MoveEventInternal(SHARED_FUNC_MOVE_EVENT, from, to); | 917 MoveEventInternal(SHARED_FUNC_MOVE_EVENT, from, to); |
| 887 #endif | 918 #endif |
| 888 } | 919 } |
| 889 | 920 |
| 890 | 921 |
| 891 #ifdef ENABLE_LOGGING_AND_PROFILING | 922 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 892 void Logger::MoveEventInternal(LogEventsAndTags event, | 923 void Logger::MoveEventInternal(LogEventsAndTags event, |
| 893 Address from, | 924 Address from, |
| 894 Address to) { | 925 Address to) { |
| 895 if (!Log::IsEnabled() || !FLAG_log_code) return; | 926 if (!log_->IsEnabled() || !FLAG_log_code) return; |
| 896 LogMessageBuilder msg; | 927 LogMessageBuilder msg(this); |
| 897 msg.Append("%s,", kLogEventsNames[event]); | 928 msg.Append("%s,", kLogEventsNames[event]); |
| 898 msg.AppendAddress(from); | 929 msg.AppendAddress(from); |
| 899 msg.Append(','); | 930 msg.Append(','); |
| 900 msg.AppendAddress(to); | 931 msg.AppendAddress(to); |
| 901 msg.Append('\n'); | 932 msg.Append('\n'); |
| 902 msg.WriteToLogFile(); | 933 msg.WriteToLogFile(); |
| 903 } | 934 } |
| 904 #endif | 935 #endif |
| 905 | 936 |
| 906 | 937 |
| 907 #ifdef ENABLE_LOGGING_AND_PROFILING | 938 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 908 void Logger::DeleteEventInternal(LogEventsAndTags event, Address from) { | 939 void Logger::DeleteEventInternal(LogEventsAndTags event, Address from) { |
| 909 if (!Log::IsEnabled() || !FLAG_log_code) return; | 940 if (!log_->IsEnabled() || !FLAG_log_code) return; |
| 910 LogMessageBuilder msg; | 941 LogMessageBuilder msg(this); |
| 911 msg.Append("%s,", kLogEventsNames[event]); | 942 msg.Append("%s,", kLogEventsNames[event]); |
| 912 msg.AppendAddress(from); | 943 msg.AppendAddress(from); |
| 913 msg.Append('\n'); | 944 msg.Append('\n'); |
| 914 msg.WriteToLogFile(); | 945 msg.WriteToLogFile(); |
| 915 } | 946 } |
| 916 #endif | 947 #endif |
| 917 | 948 |
| 918 | 949 |
| 919 void Logger::ResourceEvent(const char* name, const char* tag) { | 950 void Logger::ResourceEvent(const char* name, const char* tag) { |
| 920 #ifdef ENABLE_LOGGING_AND_PROFILING | 951 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 921 if (!Log::IsEnabled() || !FLAG_log) return; | 952 if (!log_->IsEnabled() || !FLAG_log) return; |
| 922 LogMessageBuilder msg; | 953 LogMessageBuilder msg(this); |
| 923 msg.Append("%s,%s,", name, tag); | 954 msg.Append("%s,%s,", name, tag); |
| 924 | 955 |
| 925 uint32_t sec, usec; | 956 uint32_t sec, usec; |
| 926 if (OS::GetUserTime(&sec, &usec) != -1) { | 957 if (OS::GetUserTime(&sec, &usec) != -1) { |
| 927 msg.Append("%d,%d,", sec, usec); | 958 msg.Append("%d,%d,", sec, usec); |
| 928 } | 959 } |
| 929 msg.Append("%.0f", OS::TimeCurrentMillis()); | 960 msg.Append("%.0f", OS::TimeCurrentMillis()); |
| 930 | 961 |
| 931 msg.Append('\n'); | 962 msg.Append('\n'); |
| 932 msg.WriteToLogFile(); | 963 msg.WriteToLogFile(); |
| 933 #endif | 964 #endif |
| 934 } | 965 } |
| 935 | 966 |
| 936 | 967 |
| 937 void Logger::SuspectReadEvent(String* name, Object* obj) { | 968 void Logger::SuspectReadEvent(String* name, Object* obj) { |
| 938 #ifdef ENABLE_LOGGING_AND_PROFILING | 969 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 939 if (!Log::IsEnabled() || !FLAG_log_suspect) return; | 970 if (!log_->IsEnabled() || !FLAG_log_suspect) return; |
| 940 LogMessageBuilder msg; | 971 LogMessageBuilder msg(this); |
| 941 String* class_name = obj->IsJSObject() | 972 String* class_name = obj->IsJSObject() |
| 942 ? JSObject::cast(obj)->class_name() | 973 ? JSObject::cast(obj)->class_name() |
| 943 : Heap::empty_string(); | 974 : HEAP->empty_string(); |
| 944 msg.Append("suspect-read,"); | 975 msg.Append("suspect-read,"); |
| 945 msg.Append(class_name); | 976 msg.Append(class_name); |
| 946 msg.Append(','); | 977 msg.Append(','); |
| 947 msg.Append('"'); | 978 msg.Append('"'); |
| 948 msg.Append(name); | 979 msg.Append(name); |
| 949 msg.Append('"'); | 980 msg.Append('"'); |
| 950 msg.Append('\n'); | 981 msg.Append('\n'); |
| 951 msg.WriteToLogFile(); | 982 msg.WriteToLogFile(); |
| 952 #endif | 983 #endif |
| 953 } | 984 } |
| 954 | 985 |
| 955 | 986 |
| 956 void Logger::HeapSampleBeginEvent(const char* space, const char* kind) { | 987 void Logger::HeapSampleBeginEvent(const char* space, const char* kind) { |
| 957 #ifdef ENABLE_LOGGING_AND_PROFILING | 988 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 958 if (!Log::IsEnabled() || !FLAG_log_gc) return; | 989 if (!log_->IsEnabled() || !FLAG_log_gc) return; |
| 959 LogMessageBuilder msg; | 990 LogMessageBuilder msg(this); |
| 960 // Using non-relative system time in order to be able to synchronize with | 991 // Using non-relative system time in order to be able to synchronize with |
| 961 // external memory profiling events (e.g. DOM memory size). | 992 // external memory profiling events (e.g. DOM memory size). |
| 962 msg.Append("heap-sample-begin,\"%s\",\"%s\",%.0f\n", | 993 msg.Append("heap-sample-begin,\"%s\",\"%s\",%.0f\n", |
| 963 space, kind, OS::TimeCurrentMillis()); | 994 space, kind, OS::TimeCurrentMillis()); |
| 964 msg.WriteToLogFile(); | 995 msg.WriteToLogFile(); |
| 965 #endif | 996 #endif |
| 966 } | 997 } |
| 967 | 998 |
| 968 | 999 |
| 969 void Logger::HeapSampleStats(const char* space, const char* kind, | 1000 void Logger::HeapSampleStats(const char* space, const char* kind, |
| 970 intptr_t capacity, intptr_t used) { | 1001 intptr_t capacity, intptr_t used) { |
| 971 #ifdef ENABLE_LOGGING_AND_PROFILING | 1002 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 972 if (!Log::IsEnabled() || !FLAG_log_gc) return; | 1003 if (!log_->IsEnabled() || !FLAG_log_gc) return; |
| 973 LogMessageBuilder msg; | 1004 LogMessageBuilder msg(this); |
| 974 msg.Append("heap-sample-stats,\"%s\",\"%s\"," | 1005 msg.Append("heap-sample-stats,\"%s\",\"%s\"," |
| 975 "%" V8_PTR_PREFIX "d,%" V8_PTR_PREFIX "d\n", | 1006 "%" V8_PTR_PREFIX "d,%" V8_PTR_PREFIX "d\n", |
| 976 space, kind, capacity, used); | 1007 space, kind, capacity, used); |
| 977 msg.WriteToLogFile(); | 1008 msg.WriteToLogFile(); |
| 978 #endif | 1009 #endif |
| 979 } | 1010 } |
| 980 | 1011 |
| 981 | 1012 |
| 982 void Logger::HeapSampleEndEvent(const char* space, const char* kind) { | 1013 void Logger::HeapSampleEndEvent(const char* space, const char* kind) { |
| 983 #ifdef ENABLE_LOGGING_AND_PROFILING | 1014 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 984 if (!Log::IsEnabled() || !FLAG_log_gc) return; | 1015 if (!log_->IsEnabled() || !FLAG_log_gc) return; |
| 985 LogMessageBuilder msg; | 1016 LogMessageBuilder msg(this); |
| 986 msg.Append("heap-sample-end,\"%s\",\"%s\"\n", space, kind); | 1017 msg.Append("heap-sample-end,\"%s\",\"%s\"\n", space, kind); |
| 987 msg.WriteToLogFile(); | 1018 msg.WriteToLogFile(); |
| 988 #endif | 1019 #endif |
| 989 } | 1020 } |
| 990 | 1021 |
| 991 | 1022 |
| 992 void Logger::HeapSampleItemEvent(const char* type, int number, int bytes) { | 1023 void Logger::HeapSampleItemEvent(const char* type, int number, int bytes) { |
| 993 #ifdef ENABLE_LOGGING_AND_PROFILING | 1024 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 994 if (!Log::IsEnabled() || !FLAG_log_gc) return; | 1025 if (!log_->IsEnabled() || !FLAG_log_gc) return; |
| 995 LogMessageBuilder msg; | 1026 LogMessageBuilder msg(this); |
| 996 msg.Append("heap-sample-item,%s,%d,%d\n", type, number, bytes); | 1027 msg.Append("heap-sample-item,%s,%d,%d\n", type, number, bytes); |
| 997 msg.WriteToLogFile(); | 1028 msg.WriteToLogFile(); |
| 998 #endif | 1029 #endif |
| 999 } | 1030 } |
| 1000 | 1031 |
| 1001 | 1032 |
| 1002 void Logger::HeapSampleJSConstructorEvent(const char* constructor, | 1033 void Logger::HeapSampleJSConstructorEvent(const char* constructor, |
| 1003 int number, int bytes) { | 1034 int number, int bytes) { |
| 1004 #ifdef ENABLE_LOGGING_AND_PROFILING | 1035 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 1005 if (!Log::IsEnabled() || !FLAG_log_gc) return; | 1036 if (!log_->IsEnabled() || !FLAG_log_gc) return; |
| 1006 LogMessageBuilder msg; | 1037 LogMessageBuilder msg(this); |
| 1007 msg.Append("heap-js-cons-item,%s,%d,%d\n", constructor, number, bytes); | 1038 msg.Append("heap-js-cons-item,%s,%d,%d\n", constructor, number, bytes); |
| 1008 msg.WriteToLogFile(); | 1039 msg.WriteToLogFile(); |
| 1009 #endif | 1040 #endif |
| 1010 } | 1041 } |
| 1011 | 1042 |
| 1043 // Event starts with comma, so we don't have it in the format string. |
| 1044 static const char kEventText[] = "heap-js-ret-item,%s"; |
| 1045 // We take placeholder strings into account, but it's OK to be conservative. |
| 1046 static const int kEventTextLen = sizeof(kEventText)/sizeof(kEventText[0]); |
| 1012 | 1047 |
| 1013 void Logger::HeapSampleJSRetainersEvent( | 1048 void Logger::HeapSampleJSRetainersEvent( |
| 1014 const char* constructor, const char* event) { | 1049 const char* constructor, const char* event) { |
| 1015 #ifdef ENABLE_LOGGING_AND_PROFILING | 1050 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 1016 if (!Log::IsEnabled() || !FLAG_log_gc) return; | 1051 if (!log_->IsEnabled() || !FLAG_log_gc) return; |
| 1017 // Event starts with comma, so we don't have it in the format string. | |
| 1018 static const char* event_text = "heap-js-ret-item,%s"; | |
| 1019 // We take placeholder strings into account, but it's OK to be conservative. | |
| 1020 static const int event_text_len = StrLength(event_text); | |
| 1021 const int cons_len = StrLength(constructor); | 1052 const int cons_len = StrLength(constructor); |
| 1022 const int event_len = StrLength(event); | 1053 const int event_len = StrLength(event); |
| 1023 int pos = 0; | 1054 int pos = 0; |
| 1024 // Retainer lists can be long. We may need to split them into multiple events. | 1055 // Retainer lists can be long. We may need to split them into multiple events. |
| 1025 do { | 1056 do { |
| 1026 LogMessageBuilder msg; | 1057 LogMessageBuilder msg(this); |
| 1027 msg.Append(event_text, constructor); | 1058 msg.Append(kEventText, constructor); |
| 1028 int to_write = event_len - pos; | 1059 int to_write = event_len - pos; |
| 1029 if (to_write > Log::kMessageBufferSize - (cons_len + event_text_len)) { | 1060 if (to_write > Log::kMessageBufferSize - (cons_len + kEventTextLen)) { |
| 1030 int cut_pos = pos + Log::kMessageBufferSize - (cons_len + event_text_len); | 1061 int cut_pos = pos + Log::kMessageBufferSize - (cons_len + kEventTextLen); |
| 1031 ASSERT(cut_pos < event_len); | 1062 ASSERT(cut_pos < event_len); |
| 1032 while (cut_pos > pos && event[cut_pos] != ',') --cut_pos; | 1063 while (cut_pos > pos && event[cut_pos] != ',') --cut_pos; |
| 1033 if (event[cut_pos] != ',') { | 1064 if (event[cut_pos] != ',') { |
| 1034 // Crash in debug mode, skip in release mode. | 1065 // Crash in debug mode, skip in release mode. |
| 1035 ASSERT(false); | 1066 ASSERT(false); |
| 1036 return; | 1067 return; |
| 1037 } | 1068 } |
| 1038 // Append a piece of event that fits, without trailing comma. | 1069 // Append a piece of event that fits, without trailing comma. |
| 1039 msg.AppendStringPart(event + pos, cut_pos - pos); | 1070 msg.AppendStringPart(event + pos, cut_pos - pos); |
| 1040 // Start next piece with comma. | 1071 // Start next piece with comma. |
| 1041 pos = cut_pos; | 1072 pos = cut_pos; |
| 1042 } else { | 1073 } else { |
| 1043 msg.Append("%s", event + pos); | 1074 msg.Append("%s", event + pos); |
| 1044 pos += event_len; | 1075 pos += event_len; |
| 1045 } | 1076 } |
| 1046 msg.Append('\n'); | 1077 msg.Append('\n'); |
| 1047 msg.WriteToLogFile(); | 1078 msg.WriteToLogFile(); |
| 1048 } while (pos < event_len); | 1079 } while (pos < event_len); |
| 1049 #endif | 1080 #endif |
| 1050 } | 1081 } |
| 1051 | 1082 |
| 1052 | 1083 |
| 1053 void Logger::HeapSampleJSProducerEvent(const char* constructor, | 1084 void Logger::HeapSampleJSProducerEvent(const char* constructor, |
| 1054 Address* stack) { | 1085 Address* stack) { |
| 1055 #ifdef ENABLE_LOGGING_AND_PROFILING | 1086 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 1056 if (!Log::IsEnabled() || !FLAG_log_gc) return; | 1087 if (!log_->IsEnabled() || !FLAG_log_gc) return; |
| 1057 LogMessageBuilder msg; | 1088 LogMessageBuilder msg(this); |
| 1058 msg.Append("heap-js-prod-item,%s", constructor); | 1089 msg.Append("heap-js-prod-item,%s", constructor); |
| 1059 while (*stack != NULL) { | 1090 while (*stack != NULL) { |
| 1060 msg.Append(",0x%" V8PRIxPTR, *stack++); | 1091 msg.Append(",0x%" V8PRIxPTR, *stack++); |
| 1061 } | 1092 } |
| 1062 msg.Append("\n"); | 1093 msg.Append("\n"); |
| 1063 msg.WriteToLogFile(); | 1094 msg.WriteToLogFile(); |
| 1064 #endif | 1095 #endif |
| 1065 } | 1096 } |
| 1066 | 1097 |
| 1067 | 1098 |
| 1068 void Logger::DebugTag(const char* call_site_tag) { | 1099 void Logger::DebugTag(const char* call_site_tag) { |
| 1069 #ifdef ENABLE_LOGGING_AND_PROFILING | 1100 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 1070 if (!Log::IsEnabled() || !FLAG_log) return; | 1101 if (!log_->IsEnabled() || !FLAG_log) return; |
| 1071 LogMessageBuilder msg; | 1102 LogMessageBuilder msg(this); |
| 1072 msg.Append("debug-tag,%s\n", call_site_tag); | 1103 msg.Append("debug-tag,%s\n", call_site_tag); |
| 1073 msg.WriteToLogFile(); | 1104 msg.WriteToLogFile(); |
| 1074 #endif | 1105 #endif |
| 1075 } | 1106 } |
| 1076 | 1107 |
| 1077 | 1108 |
| 1078 void Logger::DebugEvent(const char* event_type, Vector<uint16_t> parameter) { | 1109 void Logger::DebugEvent(const char* event_type, Vector<uint16_t> parameter) { |
| 1079 #ifdef ENABLE_LOGGING_AND_PROFILING | 1110 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 1080 if (!Log::IsEnabled() || !FLAG_log) return; | 1111 if (!log_->IsEnabled() || !FLAG_log) return; |
| 1081 StringBuilder s(parameter.length() + 1); | 1112 StringBuilder s(parameter.length() + 1); |
| 1082 for (int i = 0; i < parameter.length(); ++i) { | 1113 for (int i = 0; i < parameter.length(); ++i) { |
| 1083 s.AddCharacter(static_cast<char>(parameter[i])); | 1114 s.AddCharacter(static_cast<char>(parameter[i])); |
| 1084 } | 1115 } |
| 1085 char* parameter_string = s.Finalize(); | 1116 char* parameter_string = s.Finalize(); |
| 1086 LogMessageBuilder msg; | 1117 LogMessageBuilder msg(this); |
| 1087 msg.Append("debug-queue-event,%s,%15.3f,%s\n", | 1118 msg.Append("debug-queue-event,%s,%15.3f,%s\n", |
| 1088 event_type, | 1119 event_type, |
| 1089 OS::TimeCurrentMillis(), | 1120 OS::TimeCurrentMillis(), |
| 1090 parameter_string); | 1121 parameter_string); |
| 1091 DeleteArray(parameter_string); | 1122 DeleteArray(parameter_string); |
| 1092 msg.WriteToLogFile(); | 1123 msg.WriteToLogFile(); |
| 1093 #endif | 1124 #endif |
| 1094 } | 1125 } |
| 1095 | 1126 |
| 1096 | 1127 |
| 1097 #ifdef ENABLE_LOGGING_AND_PROFILING | 1128 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 1098 void Logger::TickEvent(TickSample* sample, bool overflow) { | 1129 void Logger::TickEvent(TickSample* sample, bool overflow) { |
| 1099 if (!Log::IsEnabled() || !FLAG_prof) return; | 1130 if (!log_->IsEnabled() || !FLAG_prof) return; |
| 1100 LogMessageBuilder msg; | 1131 LogMessageBuilder msg(this); |
| 1101 msg.Append("%s,", kLogEventsNames[TICK_EVENT]); | 1132 msg.Append("%s,", kLogEventsNames[TICK_EVENT]); |
| 1102 msg.AppendAddress(sample->pc); | 1133 msg.AppendAddress(sample->pc); |
| 1103 msg.Append(','); | 1134 msg.Append(','); |
| 1104 msg.AppendAddress(sample->sp); | 1135 msg.AppendAddress(sample->sp); |
| 1105 msg.Append(','); | 1136 msg.Append(','); |
| 1106 msg.AppendAddress(sample->tos); | 1137 msg.AppendAddress(sample->tos); |
| 1107 msg.Append(",%d", static_cast<int>(sample->state)); | 1138 msg.Append(",%d", static_cast<int>(sample->state)); |
| 1108 if (overflow) { | 1139 if (overflow) { |
| 1109 msg.Append(",overflow"); | 1140 msg.Append(",overflow"); |
| 1110 } | 1141 } |
| (...skipping 12 matching lines...) Expand all Loading... |
| 1123 result |= PROFILER_MODULE_CPU; | 1154 result |= PROFILER_MODULE_CPU; |
| 1124 } | 1155 } |
| 1125 if (FLAG_log_gc) { | 1156 if (FLAG_log_gc) { |
| 1126 result |= PROFILER_MODULE_HEAP_STATS | PROFILER_MODULE_JS_CONSTRUCTORS; | 1157 result |= PROFILER_MODULE_HEAP_STATS | PROFILER_MODULE_JS_CONSTRUCTORS; |
| 1127 } | 1158 } |
| 1128 return result; | 1159 return result; |
| 1129 } | 1160 } |
| 1130 | 1161 |
| 1131 | 1162 |
| 1132 void Logger::PauseProfiler(int flags, int tag) { | 1163 void Logger::PauseProfiler(int flags, int tag) { |
| 1133 if (!Log::IsEnabled()) return; | 1164 if (!log_->IsEnabled()) return; |
| 1134 if (profiler_ != NULL && (flags & PROFILER_MODULE_CPU)) { | 1165 if (profiler_ != NULL && (flags & PROFILER_MODULE_CPU)) { |
| 1135 // It is OK to have negative nesting. | 1166 // It is OK to have negative nesting. |
| 1136 if (--cpu_profiler_nesting_ == 0) { | 1167 if (--cpu_profiler_nesting_ == 0) { |
| 1137 profiler_->pause(); | 1168 profiler_->pause(); |
| 1138 if (FLAG_prof_lazy) { | 1169 if (FLAG_prof_lazy) { |
| 1139 if (!FLAG_sliding_state_window && !RuntimeProfiler::IsEnabled()) { | 1170 if (!FLAG_sliding_state_window && !RuntimeProfiler::IsEnabled()) { |
| 1140 ticker_->Stop(); | 1171 ticker_->Stop(); |
| 1141 } | 1172 } |
| 1142 FLAG_log_code = false; | 1173 FLAG_log_code = false; |
| 1143 // Must be the same message as Log::kDynamicBufferSeal. | 1174 // Must be the same message as Log::kDynamicBufferSeal. |
| 1144 LOG(UncheckedStringEvent("profiler", "pause")); | 1175 LOG(ISOLATE, UncheckedStringEvent("profiler", "pause")); |
| 1145 } | 1176 } |
| 1146 --logging_nesting_; | 1177 --logging_nesting_; |
| 1147 } | 1178 } |
| 1148 } | 1179 } |
| 1149 if (flags & | 1180 if (flags & |
| 1150 (PROFILER_MODULE_HEAP_STATS | PROFILER_MODULE_JS_CONSTRUCTORS)) { | 1181 (PROFILER_MODULE_HEAP_STATS | PROFILER_MODULE_JS_CONSTRUCTORS)) { |
| 1151 if (--heap_profiler_nesting_ == 0) { | 1182 if (--heap_profiler_nesting_ == 0) { |
| 1152 FLAG_log_gc = false; | 1183 FLAG_log_gc = false; |
| 1153 --logging_nesting_; | 1184 --logging_nesting_; |
| 1154 } | 1185 } |
| 1155 } | 1186 } |
| 1156 if (tag != 0) { | 1187 if (tag != 0) { |
| 1157 UncheckedIntEvent("close-tag", tag); | 1188 UncheckedIntEvent("close-tag", tag); |
| 1158 } | 1189 } |
| 1159 } | 1190 } |
| 1160 | 1191 |
| 1161 | 1192 |
| 1162 void Logger::ResumeProfiler(int flags, int tag) { | 1193 void Logger::ResumeProfiler(int flags, int tag) { |
| 1163 if (!Log::IsEnabled()) return; | 1194 if (!log_->IsEnabled()) return; |
| 1164 if (tag != 0) { | 1195 if (tag != 0) { |
| 1165 UncheckedIntEvent("open-tag", tag); | 1196 UncheckedIntEvent("open-tag", tag); |
| 1166 } | 1197 } |
| 1167 if (profiler_ != NULL && (flags & PROFILER_MODULE_CPU)) { | 1198 if (profiler_ != NULL && (flags & PROFILER_MODULE_CPU)) { |
| 1168 if (cpu_profiler_nesting_++ == 0) { | 1199 if (cpu_profiler_nesting_++ == 0) { |
| 1169 ++logging_nesting_; | 1200 ++logging_nesting_; |
| 1170 if (FLAG_prof_lazy) { | 1201 if (FLAG_prof_lazy) { |
| 1171 profiler_->Engage(); | 1202 profiler_->Engage(); |
| 1172 LOG(UncheckedStringEvent("profiler", "resume")); | 1203 LOG(ISOLATE, UncheckedStringEvent("profiler", "resume")); |
| 1173 FLAG_log_code = true; | 1204 FLAG_log_code = true; |
| 1174 LogCompiledFunctions(); | 1205 LogCompiledFunctions(); |
| 1175 LogAccessorCallbacks(); | 1206 LogAccessorCallbacks(); |
| 1176 if (!FLAG_sliding_state_window && !ticker_->IsActive()) { | 1207 if (!FLAG_sliding_state_window && !ticker_->IsActive()) { |
| 1177 ticker_->Start(); | 1208 ticker_->Start(); |
| 1178 } | 1209 } |
| 1179 } | 1210 } |
| 1180 profiler_->resume(); | 1211 profiler_->resume(); |
| 1181 } | 1212 } |
| 1182 } | 1213 } |
| 1183 if (flags & | 1214 if (flags & |
| 1184 (PROFILER_MODULE_HEAP_STATS | PROFILER_MODULE_JS_CONSTRUCTORS)) { | 1215 (PROFILER_MODULE_HEAP_STATS | PROFILER_MODULE_JS_CONSTRUCTORS)) { |
| 1185 if (heap_profiler_nesting_++ == 0) { | 1216 if (heap_profiler_nesting_++ == 0) { |
| 1186 ++logging_nesting_; | 1217 ++logging_nesting_; |
| 1187 FLAG_log_gc = true; | 1218 FLAG_log_gc = true; |
| 1188 } | 1219 } |
| 1189 } | 1220 } |
| 1190 } | 1221 } |
| 1191 | 1222 |
| 1192 | 1223 |
| 1193 // This function can be called when Log's mutex is acquired, | 1224 // This function can be called when Log's mutex is acquired, |
| 1194 // either from main or Profiler's thread. | 1225 // either from main or Profiler's thread. |
| 1195 void Logger::StopLoggingAndProfiling() { | 1226 void Logger::LogFailure() { |
| 1196 Log::stop(); | |
| 1197 PauseProfiler(PROFILER_MODULE_CPU, 0); | 1227 PauseProfiler(PROFILER_MODULE_CPU, 0); |
| 1198 } | 1228 } |
| 1199 | 1229 |
| 1200 | 1230 |
| 1201 bool Logger::IsProfilerSamplerActive() { | 1231 bool Logger::IsProfilerSamplerActive() { |
| 1202 return ticker_->IsActive(); | 1232 return ticker_->IsActive(); |
| 1203 } | 1233 } |
| 1204 | 1234 |
| 1205 | 1235 |
| 1206 int Logger::GetLogLines(int from_pos, char* dest_buf, int max_size) { | 1236 int Logger::GetLogLines(int from_pos, char* dest_buf, int max_size) { |
| 1207 return Log::GetLogLines(from_pos, dest_buf, max_size); | 1237 return log_->GetLogLines(from_pos, dest_buf, max_size); |
| 1208 } | 1238 } |
| 1209 | 1239 |
| 1210 | 1240 |
| 1211 class EnumerateOptimizedFunctionsVisitor: public OptimizedFunctionVisitor { | 1241 class EnumerateOptimizedFunctionsVisitor: public OptimizedFunctionVisitor { |
| 1212 public: | 1242 public: |
| 1213 EnumerateOptimizedFunctionsVisitor(Handle<SharedFunctionInfo>* sfis, | 1243 EnumerateOptimizedFunctionsVisitor(Handle<SharedFunctionInfo>* sfis, |
| 1214 Handle<Code>* code_objects, | 1244 Handle<Code>* code_objects, |
| 1215 int* count) | 1245 int* count) |
| 1216 : sfis_(sfis), code_objects_(code_objects), count_(count) { } | 1246 : sfis_(sfis), code_objects_(code_objects), count_(count) { } |
| 1217 | 1247 |
| (...skipping 101 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 1319 break; | 1349 break; |
| 1320 case Code::CALL_IC: | 1350 case Code::CALL_IC: |
| 1321 description = "A call IC from the snapshot"; | 1351 description = "A call IC from the snapshot"; |
| 1322 tag = Logger::CALL_IC_TAG; | 1352 tag = Logger::CALL_IC_TAG; |
| 1323 break; | 1353 break; |
| 1324 case Code::KEYED_CALL_IC: | 1354 case Code::KEYED_CALL_IC: |
| 1325 description = "A keyed call IC from the snapshot"; | 1355 description = "A keyed call IC from the snapshot"; |
| 1326 tag = Logger::KEYED_CALL_IC_TAG; | 1356 tag = Logger::KEYED_CALL_IC_TAG; |
| 1327 break; | 1357 break; |
| 1328 } | 1358 } |
| 1329 PROFILE(CodeCreateEvent(tag, code_object, description)); | 1359 PROFILE(ISOLATE, CodeCreateEvent(tag, code_object, description)); |
| 1330 } | 1360 } |
| 1331 } | 1361 } |
| 1332 | 1362 |
| 1333 | 1363 |
| 1334 void Logger::LogCodeInfo() { | 1364 void Logger::LogCodeInfo() { |
| 1335 #ifdef ENABLE_LOGGING_AND_PROFILING | 1365 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 1336 if (!Log::IsEnabled() || !FLAG_log_code || !FLAG_ll_prof) return; | 1366 if (!log_->IsEnabled() || !FLAG_log_code || !FLAG_ll_prof) return; |
| 1337 #if V8_TARGET_ARCH_IA32 | 1367 #if V8_TARGET_ARCH_IA32 |
| 1338 const char arch[] = "ia32"; | 1368 const char arch[] = "ia32"; |
| 1339 #elif V8_TARGET_ARCH_X64 | 1369 #elif V8_TARGET_ARCH_X64 |
| 1340 const char arch[] = "x64"; | 1370 const char arch[] = "x64"; |
| 1341 #elif V8_TARGET_ARCH_ARM | 1371 #elif V8_TARGET_ARCH_ARM |
| 1342 const char arch[] = "arm"; | 1372 const char arch[] = "arm"; |
| 1343 #else | 1373 #else |
| 1344 const char arch[] = "unknown"; | 1374 const char arch[] = "unknown"; |
| 1345 #endif | 1375 #endif |
| 1346 LogMessageBuilder msg; | 1376 LogMessageBuilder msg(this); |
| 1347 msg.Append("code-info,%s,%d\n", arch, Code::kHeaderSize); | 1377 msg.Append("code-info,%s,%d\n", arch, Code::kHeaderSize); |
| 1348 msg.WriteToLogFile(); | 1378 msg.WriteToLogFile(); |
| 1349 #endif // ENABLE_LOGGING_AND_PROFILING | 1379 #endif // ENABLE_LOGGING_AND_PROFILING |
| 1350 } | 1380 } |
| 1351 | 1381 |
| 1352 | 1382 |
| 1353 void Logger::LowLevelCodeCreateEvent(Code* code, LogMessageBuilder* msg) { | 1383 void Logger::LowLevelCodeCreateEvent(Code* code, LogMessageBuilder* msg) { |
| 1354 if (!FLAG_ll_prof || Log::output_code_handle_ == NULL) return; | 1384 if (!FLAG_ll_prof || log_->output_code_handle_ == NULL) return; |
| 1355 int pos = static_cast<int>(ftell(Log::output_code_handle_)); | 1385 int pos = static_cast<int>(ftell(log_->output_code_handle_)); |
| 1356 size_t rv = fwrite(code->instruction_start(), 1, code->instruction_size(), | 1386 size_t rv = fwrite(code->instruction_start(), 1, code->instruction_size(), |
| 1357 Log::output_code_handle_); | 1387 log_->output_code_handle_); |
| 1358 ASSERT(static_cast<size_t>(code->instruction_size()) == rv); | 1388 ASSERT(static_cast<size_t>(code->instruction_size()) == rv); |
| 1359 USE(rv); | 1389 USE(rv); |
| 1360 msg->Append(",%d", pos); | 1390 msg->Append(",%d", pos); |
| 1361 } | 1391 } |
| 1362 | 1392 |
| 1363 | 1393 |
| 1364 void Logger::LogCodeObjects() { | 1394 void Logger::LogCodeObjects() { |
| 1365 AssertNoAllocation no_alloc; | 1395 AssertNoAllocation no_alloc; |
| 1366 HeapIterator iterator; | 1396 HeapIterator iterator; |
| 1367 for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) { | 1397 for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) { |
| 1368 if (obj->IsCode()) LogCodeObject(obj); | 1398 if (obj->IsCode()) LogCodeObject(obj); |
| 1369 } | 1399 } |
| 1370 } | 1400 } |
| 1371 | 1401 |
| 1372 | 1402 |
| 1373 void Logger::LogCompiledFunctions() { | 1403 void Logger::LogCompiledFunctions() { |
| 1374 HandleScope scope; | 1404 HandleScope scope; |
| 1375 const int compiled_funcs_count = EnumerateCompiledFunctions(NULL, NULL); | 1405 const int compiled_funcs_count = EnumerateCompiledFunctions(NULL, NULL); |
| 1376 ScopedVector< Handle<SharedFunctionInfo> > sfis(compiled_funcs_count); | 1406 ScopedVector< Handle<SharedFunctionInfo> > sfis(compiled_funcs_count); |
| 1377 ScopedVector< Handle<Code> > code_objects(compiled_funcs_count); | 1407 ScopedVector< Handle<Code> > code_objects(compiled_funcs_count); |
| 1378 EnumerateCompiledFunctions(sfis.start(), code_objects.start()); | 1408 EnumerateCompiledFunctions(sfis.start(), code_objects.start()); |
| 1379 | 1409 |
| 1380 // During iteration, there can be heap allocation due to | 1410 // During iteration, there can be heap allocation due to |
| 1381 // GetScriptLineNumber call. | 1411 // GetScriptLineNumber call. |
| 1382 for (int i = 0; i < compiled_funcs_count; ++i) { | 1412 for (int i = 0; i < compiled_funcs_count; ++i) { |
| 1383 if (*code_objects[i] == Builtins::builtin(Builtins::LazyCompile)) continue; | 1413 if (*code_objects[i] == Isolate::Current()->builtins()->builtin( |
| 1414 Builtins::LazyCompile)) |
| 1415 continue; |
| 1384 Handle<SharedFunctionInfo> shared = sfis[i]; | 1416 Handle<SharedFunctionInfo> shared = sfis[i]; |
| 1385 Handle<String> func_name(shared->DebugName()); | 1417 Handle<String> func_name(shared->DebugName()); |
| 1386 if (shared->script()->IsScript()) { | 1418 if (shared->script()->IsScript()) { |
| 1387 Handle<Script> script(Script::cast(shared->script())); | 1419 Handle<Script> script(Script::cast(shared->script())); |
| 1388 if (script->name()->IsString()) { | 1420 if (script->name()->IsString()) { |
| 1389 Handle<String> script_name(String::cast(script->name())); | 1421 Handle<String> script_name(String::cast(script->name())); |
| 1390 int line_num = GetScriptLineNumber(script, shared->start_position()); | 1422 int line_num = GetScriptLineNumber(script, shared->start_position()); |
| 1391 if (line_num > 0) { | 1423 if (line_num > 0) { |
| 1392 PROFILE(CodeCreateEvent( | 1424 PROFILE(ISOLATE, |
| 1393 Logger::ToNativeByScript(Logger::LAZY_COMPILE_TAG, *script), | 1425 CodeCreateEvent( |
| 1394 *code_objects[i], *shared, | 1426 Logger::ToNativeByScript(Logger::LAZY_COMPILE_TAG, *script), |
| 1395 *script_name, line_num + 1)); | 1427 *code_objects[i], *shared, |
| 1428 *script_name, line_num + 1)); |
| 1396 } else { | 1429 } else { |
| 1397 // Can't distinguish eval and script here, so always use Script. | 1430 // Can't distinguish eval and script here, so always use Script. |
| 1398 PROFILE(CodeCreateEvent( | 1431 PROFILE(ISOLATE, |
| 1399 Logger::ToNativeByScript(Logger::SCRIPT_TAG, *script), | 1432 CodeCreateEvent( |
| 1400 *code_objects[i], *shared, *script_name)); | 1433 Logger::ToNativeByScript(Logger::SCRIPT_TAG, *script), |
| 1434 *code_objects[i], *shared, *script_name)); |
| 1401 } | 1435 } |
| 1402 } else { | 1436 } else { |
| 1403 PROFILE(CodeCreateEvent( | 1437 PROFILE(ISOLATE, |
| 1404 Logger::ToNativeByScript(Logger::LAZY_COMPILE_TAG, *script), | 1438 CodeCreateEvent( |
| 1405 *code_objects[i], *shared, *func_name)); | 1439 Logger::ToNativeByScript(Logger::LAZY_COMPILE_TAG, *script), |
| 1440 *code_objects[i], *shared, *func_name)); |
| 1406 } | 1441 } |
| 1407 } else if (shared->IsApiFunction()) { | 1442 } else if (shared->IsApiFunction()) { |
| 1408 // API function. | 1443 // API function. |
| 1409 FunctionTemplateInfo* fun_data = shared->get_api_func_data(); | 1444 FunctionTemplateInfo* fun_data = shared->get_api_func_data(); |
| 1410 Object* raw_call_data = fun_data->call_code(); | 1445 Object* raw_call_data = fun_data->call_code(); |
| 1411 if (!raw_call_data->IsUndefined()) { | 1446 if (!raw_call_data->IsUndefined()) { |
| 1412 CallHandlerInfo* call_data = CallHandlerInfo::cast(raw_call_data); | 1447 CallHandlerInfo* call_data = CallHandlerInfo::cast(raw_call_data); |
| 1413 Object* callback_obj = call_data->callback(); | 1448 Object* callback_obj = call_data->callback(); |
| 1414 Address entry_point = v8::ToCData<Address>(callback_obj); | 1449 Address entry_point = v8::ToCData<Address>(callback_obj); |
| 1415 PROFILE(CallbackEvent(*func_name, entry_point)); | 1450 PROFILE(ISOLATE, CallbackEvent(*func_name, entry_point)); |
| 1416 } | 1451 } |
| 1417 } else { | 1452 } else { |
| 1418 PROFILE(CodeCreateEvent( | 1453 PROFILE(ISOLATE, |
| 1419 Logger::LAZY_COMPILE_TAG, *code_objects[i], *shared, *func_name)); | 1454 CodeCreateEvent( |
| 1455 Logger::LAZY_COMPILE_TAG, *code_objects[i], |
| 1456 *shared, *func_name)); |
| 1420 } | 1457 } |
| 1421 } | 1458 } |
| 1422 } | 1459 } |
| 1423 | 1460 |
| 1424 | 1461 |
| 1425 void Logger::LogAccessorCallbacks() { | 1462 void Logger::LogAccessorCallbacks() { |
| 1426 AssertNoAllocation no_alloc; | 1463 AssertNoAllocation no_alloc; |
| 1427 HeapIterator iterator; | 1464 HeapIterator iterator; |
| 1465 i::Isolate* isolate = ISOLATE; |
| 1428 for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) { | 1466 for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) { |
| 1429 if (!obj->IsAccessorInfo()) continue; | 1467 if (!obj->IsAccessorInfo()) continue; |
| 1430 AccessorInfo* ai = AccessorInfo::cast(obj); | 1468 AccessorInfo* ai = AccessorInfo::cast(obj); |
| 1431 if (!ai->name()->IsString()) continue; | 1469 if (!ai->name()->IsString()) continue; |
| 1432 String* name = String::cast(ai->name()); | 1470 String* name = String::cast(ai->name()); |
| 1433 Address getter_entry = v8::ToCData<Address>(ai->getter()); | 1471 Address getter_entry = v8::ToCData<Address>(ai->getter()); |
| 1434 if (getter_entry != 0) { | 1472 if (getter_entry != 0) { |
| 1435 PROFILE(GetterCallbackEvent(name, getter_entry)); | 1473 PROFILE(isolate, GetterCallbackEvent(name, getter_entry)); |
| 1436 } | 1474 } |
| 1437 Address setter_entry = v8::ToCData<Address>(ai->setter()); | 1475 Address setter_entry = v8::ToCData<Address>(ai->setter()); |
| 1438 if (setter_entry != 0) { | 1476 if (setter_entry != 0) { |
| 1439 PROFILE(SetterCallbackEvent(name, setter_entry)); | 1477 PROFILE(isolate, SetterCallbackEvent(name, setter_entry)); |
| 1440 } | 1478 } |
| 1441 } | 1479 } |
| 1442 } | 1480 } |
| 1443 | 1481 |
| 1444 #endif | 1482 #endif |
| 1445 | 1483 |
| 1446 | 1484 |
| 1447 bool Logger::Setup() { | 1485 bool Logger::Setup() { |
| 1448 #ifdef ENABLE_LOGGING_AND_PROFILING | 1486 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 1449 // --log-all enables all the log flags. | 1487 // Tests and EnsureInitialize() can call this twice in a row. It's harmless. |
| 1450 if (FLAG_log_all) { | 1488 if (is_initialized_) return true; |
| 1451 FLAG_log_runtime = true; | 1489 is_initialized_ = true; |
| 1452 FLAG_log_api = true; | |
| 1453 FLAG_log_code = true; | |
| 1454 FLAG_log_gc = true; | |
| 1455 FLAG_log_suspect = true; | |
| 1456 FLAG_log_handles = true; | |
| 1457 FLAG_log_regexp = true; | |
| 1458 } | |
| 1459 | |
| 1460 // --prof implies --log-code. | |
| 1461 if (FLAG_prof) FLAG_log_code = true; | |
| 1462 | 1490 |
| 1463 // --ll-prof implies --log-code and --log-snapshot-positions. | 1491 // --ll-prof implies --log-code and --log-snapshot-positions. |
| 1464 if (FLAG_ll_prof) { | 1492 if (FLAG_ll_prof) { |
| 1465 FLAG_log_code = true; | 1493 FLAG_log_code = true; |
| 1466 FLAG_log_snapshot_positions = true; | 1494 FLAG_log_snapshot_positions = true; |
| 1467 } | 1495 } |
| 1468 | 1496 |
| 1469 // --prof_lazy controls --log-code, implies --noprof_auto. | 1497 // --prof_lazy controls --log-code, implies --noprof_auto. |
| 1470 if (FLAG_prof_lazy) { | 1498 if (FLAG_prof_lazy) { |
| 1471 FLAG_log_code = false; | 1499 FLAG_log_code = false; |
| 1472 FLAG_prof_auto = false; | 1500 FLAG_prof_auto = false; |
| 1473 } | 1501 } |
| 1474 | 1502 |
| 1475 bool start_logging = FLAG_log || FLAG_log_runtime || FLAG_log_api | 1503 // TODO(isolates): this assert introduces cyclic dependency (logger |
| 1476 || FLAG_log_code || FLAG_log_gc || FLAG_log_handles || FLAG_log_suspect | 1504 // -> thread local top -> heap -> logger). |
| 1477 || FLAG_log_regexp || FLAG_log_state_changes; | 1505 // ASSERT(VMState::is_outermost_external()); |
| 1478 | 1506 |
| 1479 bool open_log_file = start_logging || FLAG_prof_lazy; | 1507 log_->Initialize(); |
| 1480 | |
| 1481 // If we're logging anything, we need to open the log file. | |
| 1482 if (open_log_file) { | |
| 1483 if (strcmp(FLAG_logfile, "-") == 0) { | |
| 1484 Log::OpenStdout(); | |
| 1485 } else if (strcmp(FLAG_logfile, "*") == 0) { | |
| 1486 Log::OpenMemoryBuffer(); | |
| 1487 } else if (strchr(FLAG_logfile, '%') != NULL) { | |
| 1488 // If there's a '%' in the log file name we have to expand | |
| 1489 // placeholders. | |
| 1490 HeapStringAllocator allocator; | |
| 1491 StringStream stream(&allocator); | |
| 1492 for (const char* p = FLAG_logfile; *p; p++) { | |
| 1493 if (*p == '%') { | |
| 1494 p++; | |
| 1495 switch (*p) { | |
| 1496 case '\0': | |
| 1497 // If there's a % at the end of the string we back up | |
| 1498 // one character so we can escape the loop properly. | |
| 1499 p--; | |
| 1500 break; | |
| 1501 case 't': { | |
| 1502 // %t expands to the current time in milliseconds. | |
| 1503 double time = OS::TimeCurrentMillis(); | |
| 1504 stream.Add("%.0f", FmtElm(time)); | |
| 1505 break; | |
| 1506 } | |
| 1507 case '%': | |
| 1508 // %% expands (contracts really) to %. | |
| 1509 stream.Put('%'); | |
| 1510 break; | |
| 1511 default: | |
| 1512 // All other %'s expand to themselves. | |
| 1513 stream.Put('%'); | |
| 1514 stream.Put(*p); | |
| 1515 break; | |
| 1516 } | |
| 1517 } else { | |
| 1518 stream.Put(*p); | |
| 1519 } | |
| 1520 } | |
| 1521 SmartPointer<const char> expanded = stream.ToCString(); | |
| 1522 Log::OpenFile(*expanded); | |
| 1523 } else { | |
| 1524 Log::OpenFile(FLAG_logfile); | |
| 1525 } | |
| 1526 } | |
| 1527 | 1508 |
| 1528 if (FLAG_ll_prof) LogCodeInfo(); | 1509 if (FLAG_ll_prof) LogCodeInfo(); |
| 1529 | 1510 |
| 1530 ticker_ = new Ticker(kSamplingIntervalMs); | 1511 ticker_ = new Ticker(Isolate::Current(), kSamplingIntervalMs); |
| 1531 | 1512 |
| 1532 if (FLAG_sliding_state_window && sliding_state_window_ == NULL) { | 1513 if (FLAG_sliding_state_window && sliding_state_window_ == NULL) { |
| 1533 sliding_state_window_ = new SlidingStateWindow(); | 1514 sliding_state_window_ = new SlidingStateWindow(); |
| 1534 } | 1515 } |
| 1535 | 1516 |
| 1517 bool start_logging = FLAG_log || FLAG_log_runtime || FLAG_log_api |
| 1518 || FLAG_log_code || FLAG_log_gc || FLAG_log_handles || FLAG_log_suspect |
| 1519 || FLAG_log_regexp || FLAG_log_state_changes; |
| 1520 |
| 1536 if (start_logging) { | 1521 if (start_logging) { |
| 1537 logging_nesting_ = 1; | 1522 logging_nesting_ = 1; |
| 1538 } | 1523 } |
| 1539 | 1524 |
| 1540 if (FLAG_prof) { | 1525 if (FLAG_prof) { |
| 1541 profiler_ = new Profiler(); | 1526 profiler_ = new Profiler(Isolate::Current()); |
| 1542 if (!FLAG_prof_auto) { | 1527 if (!FLAG_prof_auto) { |
| 1543 profiler_->pause(); | 1528 profiler_->pause(); |
| 1544 } else { | 1529 } else { |
| 1545 logging_nesting_ = 1; | 1530 logging_nesting_ = 1; |
| 1546 } | 1531 } |
| 1547 if (!FLAG_prof_lazy) { | 1532 if (!FLAG_prof_lazy) { |
| 1548 profiler_->Engage(); | 1533 profiler_->Engage(); |
| 1549 } | 1534 } |
| 1550 } | 1535 } |
| 1551 | 1536 |
| 1552 LogMessageBuilder::set_write_failure_handler(StopLoggingAndProfiling); | |
| 1553 return true; | 1537 return true; |
| 1554 | 1538 |
| 1555 #else | 1539 #else |
| 1556 return false; | 1540 return false; |
| 1557 #endif | 1541 #endif |
| 1558 } | 1542 } |
| 1559 | 1543 |
| 1560 | 1544 |
| 1545 Sampler* Logger::sampler() { |
| 1546 return ticker_; |
| 1547 } |
| 1548 |
| 1549 |
| 1561 void Logger::EnsureTickerStarted() { | 1550 void Logger::EnsureTickerStarted() { |
| 1562 #ifdef ENABLE_LOGGING_AND_PROFILING | 1551 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 1563 ASSERT(ticker_ != NULL); | 1552 ASSERT(ticker_ != NULL); |
| 1564 if (!ticker_->IsActive()) ticker_->Start(); | 1553 if (!ticker_->IsActive()) ticker_->Start(); |
| 1565 #endif | 1554 #endif |
| 1566 } | 1555 } |
| 1567 | 1556 |
| 1568 | 1557 |
| 1569 void Logger::EnsureTickerStopped() { | 1558 void Logger::EnsureTickerStopped() { |
| 1570 #ifdef ENABLE_LOGGING_AND_PROFILING | 1559 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 1571 if (ticker_ != NULL && ticker_->IsActive()) ticker_->Stop(); | 1560 if (ticker_ != NULL && ticker_->IsActive()) ticker_->Stop(); |
| 1572 #endif | 1561 #endif |
| 1573 } | 1562 } |
| 1574 | 1563 |
| 1575 | 1564 |
| 1576 void Logger::TearDown() { | 1565 void Logger::TearDown() { |
| 1577 #ifdef ENABLE_LOGGING_AND_PROFILING | 1566 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 1578 LogMessageBuilder::set_write_failure_handler(NULL); | 1567 if (!is_initialized_) return; |
| 1568 is_initialized_ = false; |
| 1579 | 1569 |
| 1580 // Stop the profiler before closing the file. | 1570 // Stop the profiler before closing the file. |
| 1581 if (profiler_ != NULL) { | 1571 if (profiler_ != NULL) { |
| 1582 profiler_->Disengage(); | 1572 profiler_->Disengage(); |
| 1583 delete profiler_; | 1573 delete profiler_; |
| 1584 profiler_ = NULL; | 1574 profiler_ = NULL; |
| 1585 } | 1575 } |
| 1586 | 1576 |
| 1587 delete sliding_state_window_; | 1577 delete sliding_state_window_; |
| 1588 sliding_state_window_ = NULL; | 1578 sliding_state_window_ = NULL; |
| 1589 | 1579 |
| 1590 delete ticker_; | 1580 delete ticker_; |
| 1591 ticker_ = NULL; | 1581 ticker_ = NULL; |
| 1592 | 1582 |
| 1593 Log::Close(); | 1583 log_->Close(); |
| 1594 #endif | 1584 #endif |
| 1595 } | 1585 } |
| 1596 | 1586 |
| 1597 | 1587 |
| 1598 void Logger::EnableSlidingStateWindow() { | 1588 void Logger::EnableSlidingStateWindow() { |
| 1599 #ifdef ENABLE_LOGGING_AND_PROFILING | 1589 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 1600 // If the ticker is NULL, Logger::Setup has not been called yet. In | 1590 // If the ticker is NULL, Logger::Setup has not been called yet. In |
| 1601 // that case, we set the sliding_state_window flag so that the | 1591 // that case, we set the sliding_state_window flag so that the |
| 1602 // sliding window computation will be started when Logger::Setup is | 1592 // sliding window computation will be started when Logger::Setup is |
| 1603 // called. | 1593 // called. |
| 1604 if (ticker_ == NULL) { | 1594 if (ticker_ == NULL) { |
| 1605 FLAG_sliding_state_window = true; | 1595 FLAG_sliding_state_window = true; |
| 1606 return; | 1596 return; |
| 1607 } | 1597 } |
| 1608 // Otherwise, if the sliding state window computation has not been | 1598 // Otherwise, if the sliding state window computation has not been |
| 1609 // started we do it now. | 1599 // started we do it now. |
| 1610 if (sliding_state_window_ == NULL) { | 1600 if (sliding_state_window_ == NULL) { |
| 1611 sliding_state_window_ = new SlidingStateWindow(); | 1601 sliding_state_window_ = new SlidingStateWindow(); |
| 1612 } | 1602 } |
| 1613 #endif | 1603 #endif |
| 1614 } | 1604 } |
| 1615 | 1605 |
| 1606 |
| 1607 Mutex* SamplerRegistry::mutex_ = OS::CreateMutex(); |
| 1608 List<Sampler*>* SamplerRegistry::active_samplers_ = NULL; |
| 1609 |
| 1610 |
| 1611 bool SamplerRegistry::IterateActiveSamplers(VisitSampler func, void* param) { |
| 1612 ScopedLock lock(mutex_); |
| 1613 for (int i = 0; |
| 1614 ActiveSamplersExist() && i < active_samplers_->length(); |
| 1615 ++i) { |
| 1616 func(active_samplers_->at(i), param); |
| 1617 } |
| 1618 return ActiveSamplersExist(); |
| 1619 } |
| 1620 |
| 1621 |
| 1622 static void ComputeCpuProfiling(Sampler* sampler, void* flag_ptr) { |
| 1623 bool* flag = reinterpret_cast<bool*>(flag_ptr); |
| 1624 *flag |= sampler->IsProfiling(); |
| 1625 } |
| 1626 |
| 1627 |
| 1628 SamplerRegistry::State SamplerRegistry::GetState() { |
| 1629 bool flag = false; |
| 1630 if (!IterateActiveSamplers(&ComputeCpuProfiling, &flag)) { |
| 1631 return HAS_NO_SAMPLERS; |
| 1632 } |
| 1633 return flag ? HAS_CPU_PROFILING_SAMPLERS : HAS_SAMPLERS; |
| 1634 } |
| 1635 |
| 1636 |
| 1637 void SamplerRegistry::AddActiveSampler(Sampler* sampler) { |
| 1638 ASSERT(sampler->IsActive()); |
| 1639 ScopedLock lock(mutex_); |
| 1640 if (active_samplers_ == NULL) { |
| 1641 active_samplers_ = new List<Sampler*>; |
| 1642 } else { |
| 1643 ASSERT(!active_samplers_->Contains(sampler)); |
| 1644 } |
| 1645 active_samplers_->Add(sampler); |
| 1646 } |
| 1647 |
| 1648 |
| 1649 void SamplerRegistry::RemoveActiveSampler(Sampler* sampler) { |
| 1650 ASSERT(sampler->IsActive()); |
| 1651 ScopedLock lock(mutex_); |
| 1652 ASSERT(active_samplers_ != NULL); |
| 1653 bool removed = active_samplers_->RemoveElement(sampler); |
| 1654 ASSERT(removed); |
| 1655 USE(removed); |
| 1656 } |
| 1657 |
| 1616 } } // namespace v8::internal | 1658 } } // namespace v8::internal |
| OLD | NEW |