diff options
Diffstat (limited to 'deps/v8/src/log.cc')
-rw-r--r-- | deps/v8/src/log.cc | 129 |
1 files changed, 44 insertions, 85 deletions
diff --git a/deps/v8/src/log.cc b/deps/v8/src/log.cc index a1e5a6752b..0f0ad40398 100644 --- a/deps/v8/src/log.cc +++ b/deps/v8/src/log.cc @@ -556,13 +556,20 @@ class Profiler: public Thread { } else { buffer_[head_] = *sample; head_ = Succ(head_); - buffer_semaphore_->Signal(); // Tell we have an element. + buffer_semaphore_.Signal(); // Tell we have an element. } } + virtual void Run(); + + // Pause and Resume TickSample data collection. + void pause() { paused_ = true; } + void resume() { paused_ = false; } + + private: // Waits for a signal and removes profiling data. bool Remove(TickSample* sample) { - buffer_semaphore_->Wait(); // Wait for an element. + buffer_semaphore_.Wait(); // Wait for an element. *sample = buffer_[tail_]; bool result = overflow_; tail_ = Succ(tail_); @@ -570,14 +577,6 @@ class Profiler: public Thread { return result; } - void Run(); - - // Pause and Resume TickSample data collection. - bool paused() const { return paused_; } - void pause() { paused_ = true; } - void resume() { paused_ = false; } - - private: // Returns the next index in the cyclic buffer. int Succ(int index) { return (index + 1) % kBufferSize; } @@ -589,7 +588,8 @@ class Profiler: public Thread { int head_; // Index to the buffer head. int tail_; // Index to the buffer tail. bool overflow_; // Tell whether a buffer overflow has occurred. - Semaphore* buffer_semaphore_; // Sempahore used for buffer synchronization. + // Sempahore used for buffer synchronization. + Semaphore buffer_semaphore_; // Tells whether profiler is engaged, that is, processing thread is stated. bool engaged_; @@ -622,13 +622,13 @@ class Ticker: public Sampler { ASSERT(profiler_ == NULL); profiler_ = profiler; IncreaseProfilingDepth(); - if (!FLAG_prof_lazy && !IsActive()) Start(); + if (!IsActive()) Start(); } void ClearProfiler() { - DecreaseProfilingDepth(); profiler_ = NULL; if (IsActive()) Stop(); + DecreaseProfilingDepth(); } private: @@ -645,7 +645,7 @@ Profiler::Profiler(Isolate* isolate) head_(0), tail_(0), overflow_(false), - buffer_semaphore_(OS::CreateSemaphore(0)), + buffer_semaphore_(0), engaged_(false), running_(false), paused_(false) { @@ -656,7 +656,7 @@ void Profiler::Engage() { if (engaged_) return; engaged_ = true; - OS::LogSharedLibraryAddresses(); + OS::LogSharedLibraryAddresses(isolate_); // Start thread processing the profiler buffer. running_ = true; @@ -686,7 +686,7 @@ void Profiler::Disengage() { Insert(&sample); Join(); - LOG(ISOLATE, UncheckedStringEvent("profiler", "end")); + LOG(isolate_, UncheckedStringEvent("profiler", "end")); } @@ -709,14 +709,12 @@ Logger::Logger(Isolate* isolate) ticker_(NULL), profiler_(NULL), log_events_(NULL), - logging_nesting_(0), - cpu_profiler_nesting_(0), + is_logging_(false), log_(new Log(this)), ll_logger_(NULL), jit_logger_(NULL), listeners_(5), - is_initialized_(false), - epoch_(0) { + is_initialized_(false) { } @@ -867,7 +865,7 @@ void Logger::CodeDeoptEvent(Code* code) { if (!log_->IsEnabled()) return; ASSERT(FLAG_log_internal_timer_events); Log::MessageBuilder msg(log_); - int since_epoch = static_cast<int>(OS::Ticks() - epoch_); + int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds()); msg.Append("code-deopt,%ld,%d\n", since_epoch, code->CodeSize()); msg.WriteToLogFile(); } @@ -877,7 +875,7 @@ void Logger::TimerEvent(StartEnd se, const char* name) { if (!log_->IsEnabled()) return; ASSERT(FLAG_log_internal_timer_events); Log::MessageBuilder msg(log_); - int since_epoch = static_cast<int>(OS::Ticks() - epoch_); + int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds()); const char* format = (se == START) ? "timer-event-start,\"%s\",%ld\n" : "timer-event-end,\"%s\",%ld\n"; msg.Append(format, name, since_epoch); @@ -906,8 +904,8 @@ void Logger::TimerEventScope::LogTimerEvent(StartEnd se) { const char* Logger::TimerEventScope::v8_recompile_synchronous = "V8.RecompileSynchronous"; -const char* Logger::TimerEventScope::v8_recompile_parallel = - "V8.RecompileParallel"; +const char* Logger::TimerEventScope::v8_recompile_concurrent = + "V8.RecompileConcurrent"; const char* Logger::TimerEventScope::v8_compile_full_code = "V8.CompileFullCode"; const char* Logger::TimerEventScope::v8_execute = "V8.Execute"; @@ -976,7 +974,7 @@ void Logger::LogRuntime(Vector<const char> format, if (c == '%' && i <= format.length() - 2) { i++; ASSERT('0' <= format[i] && format[i] <= '9'); - MaybeObject* maybe = args->GetElement(format[i] - '0'); + MaybeObject* maybe = args->GetElement(isolate_, format[i] - '0'); Object* obj; if (!maybe->ToObject(&obj)) { msg.Append("<exception>"); @@ -1233,7 +1231,7 @@ void Logger::CodeCreateEvent(LogEventsAndTags tag, Code* code, SharedFunctionInfo* shared, CompilationInfo* info, - Name* source, int line) { + Name* source, int line, int column) { PROFILER_LOG(CodeCreateEvent(tag, code, shared, info, source, line)); if (!is_logging_code_events()) return; @@ -1252,7 +1250,7 @@ void Logger::CodeCreateEvent(LogEventsAndTags tag, } else { msg.AppendSymbolName(Symbol::cast(source)); } - msg.Append(":%d\",", line); + msg.Append(":%d:%d\",", line, column); msg.AppendAddress(shared->address()); msg.Append(",%s", ComputeMarker(code)); msg.Append('\n'); @@ -1500,7 +1498,7 @@ void Logger::TickEvent(TickSample* sample, bool overflow) { Log::MessageBuilder msg(log_); msg.Append("%s,", kLogEventsNames[TICK_EVENT]); msg.AppendAddress(sample->pc); - msg.Append(",%ld", static_cast<int>(OS::Ticks() - epoch_)); + msg.Append(",%ld", static_cast<int>(timer_.Elapsed().InMicroseconds())); if (sample->has_external_callback) { msg.Append(",1,"); msg.AppendAddress(sample->external_callback); @@ -1521,43 +1519,11 @@ void Logger::TickEvent(TickSample* sample, bool overflow) { } -bool Logger::IsProfilerPaused() { - return profiler_ == NULL || profiler_->paused(); -} - - -void Logger::PauseProfiler() { +void Logger::StopProfiler() { if (!log_->IsEnabled()) return; if (profiler_ != NULL) { - // It is OK to have negative nesting. - if (--cpu_profiler_nesting_ == 0) { - profiler_->pause(); - if (FLAG_prof_lazy) { - ticker_->Stop(); - FLAG_log_code = false; - LOG(ISOLATE, UncheckedStringEvent("profiler", "pause")); - } - --logging_nesting_; - } - } -} - - -void Logger::ResumeProfiler() { - if (!log_->IsEnabled()) return; - if (profiler_ != NULL) { - if (cpu_profiler_nesting_++ == 0) { - ++logging_nesting_; - if (FLAG_prof_lazy) { - profiler_->Engage(); - LOG(ISOLATE, UncheckedStringEvent("profiler", "resume")); - FLAG_log_code = true; - LogCompiledFunctions(); - LogAccessorCallbacks(); - if (!ticker_->IsActive()) ticker_->Start(); - } - profiler_->resume(); - } + profiler_->pause(); + is_logging_ = false; } } @@ -1565,7 +1531,7 @@ void Logger::ResumeProfiler() { // This function can be called when Log's mutex is acquired, // either from main or Profiler's thread. void Logger::LogFailure() { - PauseProfiler(); + StopProfiler(); } @@ -1712,6 +1678,8 @@ void Logger::LogExistingFunction(Handle<SharedFunctionInfo> shared, if (shared->script()->IsScript()) { Handle<Script> script(Script::cast(shared->script())); int line_num = GetScriptLineNumber(script, shared->start_position()) + 1; + int column_num = + GetScriptColumnNumber(script, shared->start_position()) + 1; if (script->name()->IsString()) { Handle<String> script_name(String::cast(script->name())); if (line_num > 0) { @@ -1719,7 +1687,7 @@ void Logger::LogExistingFunction(Handle<SharedFunctionInfo> shared, CodeCreateEvent( Logger::ToNativeByScript(Logger::LAZY_COMPILE_TAG, *script), *code, *shared, NULL, - *script_name, line_num)); + *script_name, line_num, column_num)); } else { // Can't distinguish eval and script here, so always use Script. PROFILE(isolate_, @@ -1732,7 +1700,7 @@ void Logger::LogExistingFunction(Handle<SharedFunctionInfo> shared, CodeCreateEvent( Logger::ToNativeByScript(Logger::LAZY_COMPILE_TAG, *script), *code, *shared, NULL, - isolate_->heap()->empty_string(), line_num)); + isolate_->heap()->empty_string(), line_num, column_num)); } } else if (shared->IsApiFunction()) { // API function. @@ -1796,21 +1764,21 @@ void Logger::LogAccessorCallbacks() { } -static void AddIsolateIdIfNeeded(StringStream* stream) { - Isolate* isolate = Isolate::Current(); +static void AddIsolateIdIfNeeded(Isolate* isolate, StringStream* stream) { if (isolate->IsDefaultIsolate()) return; stream->Add("isolate-%p-", isolate); } -static SmartArrayPointer<const char> PrepareLogFileName(const char* file_name) { +static SmartArrayPointer<const char> PrepareLogFileName( + Isolate* isolate, const char* file_name) { if (strchr(file_name, '%') != NULL || - !Isolate::Current()->IsDefaultIsolate()) { + !isolate->IsDefaultIsolate()) { // If there's a '%' in the log file name we have to expand // placeholders. HeapStringAllocator allocator; StringStream stream(&allocator); - AddIsolateIdIfNeeded(&stream); + AddIsolateIdIfNeeded(isolate, &stream); for (const char* p = file_name; *p; p++) { if (*p == '%') { p++; @@ -1863,13 +1831,8 @@ bool Logger::SetUp(Isolate* isolate) { FLAG_log_snapshot_positions = true; } - // --prof_lazy controls --log-code. - if (FLAG_prof_lazy) { - FLAG_log_code = false; - } - SmartArrayPointer<const char> log_file_name = - PrepareLogFileName(FLAG_logfile); + PrepareLogFileName(isolate, FLAG_logfile); log_->Initialize(*log_file_name); if (FLAG_ll_prof) { @@ -1880,20 +1843,16 @@ bool Logger::SetUp(Isolate* isolate) { ticker_ = new Ticker(isolate, kSamplingIntervalMs); if (Log::InitLogAtStart()) { - logging_nesting_ = 1; + is_logging_ = true; } if (FLAG_prof) { profiler_ = new Profiler(isolate); - if (FLAG_prof_lazy) { - profiler_->pause(); - } else { - logging_nesting_ = 1; - profiler_->Engage(); - } + is_logging_ = true; + profiler_->Engage(); } - if (FLAG_log_internal_timer_events || FLAG_prof) epoch_ = OS::Ticks(); + if (FLAG_log_internal_timer_events || FLAG_prof) timer_.Start(); return true; } |