Commit bc5fc1db authored by Nico Hartmann's avatar Nico Hartmann Committed by V8 LUCI CQ

Revert "[counters] Improve v8.execute histogram timer"

This reverts commit 69564827.

Reason for revert: https://ci.chromium.org/ui/p/v8/builders/ci/V8%20Clusterfuzz%20Linux%20MSAN%20no%20origins/25955/overview

Original change's description:
> [counters] Improve v8.execute histogram timer
>
> - Mark uncommon timer-paths as V8_NOINLINE
> - Add explicit LongTaskNestedTimedHistogramScope class
> - Use explicit LongTaskRecordMode enum
> - Mark a few more isolate methods as const
> - Add more timer scopes:
>   - Accessors::ArrayLengthSetter
>   - v8::NewContext
>
> Bug: v8:12498, chromium:1275056
> Change-Id: I7896ee341c3c3a1fd5acf8f3f59347ff01dda9c0
> Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/3338258
> Reviewed-by: Marja Hölttä <marja@chromium.org>
> Auto-Submit: Camillo Bruni <cbruni@chromium.org>
> Reviewed-by: Jakob Kummerow <jkummerow@chromium.org>
> Commit-Queue: Jakob Kummerow <jkummerow@chromium.org>
> Cr-Commit-Position: refs/heads/main@{#78372}

Bug: v8:12498, chromium:1275056
Change-Id: I0147c57085f114201e1d5fa293282d38c81d0148
No-Presubmit: true
No-Tree-Checks: true
No-Try: true
Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/3338699
Bot-Commit: Rubber Stamper <rubber-stamper@appspot.gserviceaccount.com>
Commit-Queue: Nico Hartmann <nicohartmann@chromium.org>
Owners-Override: Nico Hartmann <nicohartmann@chromium.org>
Cr-Commit-Position: refs/heads/main@{#78373}
parent 69564827
...@@ -2088,8 +2088,8 @@ MaybeLocal<Value> Script::Run(Local<Context> context, ...@@ -2088,8 +2088,8 @@ MaybeLocal<Value> Script::Run(Local<Context> context,
ENTER_V8(isolate, context, Script, Run, MaybeLocal<Value>(), ENTER_V8(isolate, context, Script, Run, MaybeLocal<Value>(),
InternalEscapableScope); InternalEscapableScope);
i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate); i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate);
i::LongTaskNestedTimedHistogramScope execute_timer( i::NestedTimedHistogramScope execute_timer(isolate->counters()->execute(),
isolate->counters()->execute()); isolate);
i::AggregatingHistogramTimerScope histogram_timer( i::AggregatingHistogramTimerScope histogram_timer(
isolate->counters()->compile_lazy()); isolate->counters()->compile_lazy());
auto fun = i::Handle<i::JSFunction>::cast(Utils::OpenHandle(this)); auto fun = i::Handle<i::JSFunction>::cast(Utils::OpenHandle(this));
...@@ -2455,8 +2455,8 @@ MaybeLocal<Value> Module::Evaluate(Local<Context> context) { ...@@ -2455,8 +2455,8 @@ MaybeLocal<Value> Module::Evaluate(Local<Context> context) {
ENTER_V8(isolate, context, Module, Evaluate, MaybeLocal<Value>(), ENTER_V8(isolate, context, Module, Evaluate, MaybeLocal<Value>(),
InternalEscapableScope); InternalEscapableScope);
i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate); i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate);
i::LongTaskNestedTimedHistogramScope execute_timer( i::NestedTimedHistogramScope execute_timer(isolate->counters()->execute(),
isolate->counters()->execute()); isolate);
i::AggregatingHistogramTimerScope timer(isolate->counters()->compile_lazy()); i::AggregatingHistogramTimerScope timer(isolate->counters()->compile_lazy());
i::Handle<i::Module> self = Utils::OpenHandle(this); i::Handle<i::Module> self = Utils::OpenHandle(this);
...@@ -5181,8 +5181,8 @@ MaybeLocal<Value> Object::CallAsFunction(Local<Context> context, ...@@ -5181,8 +5181,8 @@ MaybeLocal<Value> Object::CallAsFunction(Local<Context> context,
ENTER_V8(isolate, context, Object, CallAsFunction, MaybeLocal<Value>(), ENTER_V8(isolate, context, Object, CallAsFunction, MaybeLocal<Value>(),
InternalEscapableScope); InternalEscapableScope);
i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate); i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate);
i::LongTaskNestedTimedHistogramScope execute_timer( i::NestedTimedHistogramScope execute_timer(isolate->counters()->execute(),
isolate->counters()->execute()); isolate);
auto self = Utils::OpenHandle(this); auto self = Utils::OpenHandle(this);
auto recv_obj = Utils::OpenHandle(*recv); auto recv_obj = Utils::OpenHandle(*recv);
STATIC_ASSERT(sizeof(v8::Local<v8::Value>) == sizeof(i::Handle<i::Object>)); STATIC_ASSERT(sizeof(v8::Local<v8::Value>) == sizeof(i::Handle<i::Object>));
...@@ -5201,8 +5201,8 @@ MaybeLocal<Value> Object::CallAsConstructor(Local<Context> context, int argc, ...@@ -5201,8 +5201,8 @@ MaybeLocal<Value> Object::CallAsConstructor(Local<Context> context, int argc,
ENTER_V8(isolate, context, Object, CallAsConstructor, MaybeLocal<Value>(), ENTER_V8(isolate, context, Object, CallAsConstructor, MaybeLocal<Value>(),
InternalEscapableScope); InternalEscapableScope);
i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate); i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate);
i::LongTaskNestedTimedHistogramScope execute_timer( i::NestedTimedHistogramScope execute_timer(isolate->counters()->execute(),
isolate->counters()->execute()); isolate);
auto self = Utils::OpenHandle(this); auto self = Utils::OpenHandle(this);
STATIC_ASSERT(sizeof(v8::Local<v8::Value>) == sizeof(i::Handle<i::Object>)); STATIC_ASSERT(sizeof(v8::Local<v8::Value>) == sizeof(i::Handle<i::Object>));
i::Handle<i::Object>* args = reinterpret_cast<i::Handle<i::Object>*>(argv); i::Handle<i::Object>* args = reinterpret_cast<i::Handle<i::Object>*>(argv);
...@@ -5240,8 +5240,8 @@ MaybeLocal<Object> Function::NewInstanceWithSideEffectType( ...@@ -5240,8 +5240,8 @@ MaybeLocal<Object> Function::NewInstanceWithSideEffectType(
ENTER_V8(isolate, context, Function, NewInstance, MaybeLocal<Object>(), ENTER_V8(isolate, context, Function, NewInstance, MaybeLocal<Object>(),
InternalEscapableScope); InternalEscapableScope);
i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate); i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate);
i::LongTaskNestedTimedHistogramScope execute_timer( i::NestedTimedHistogramScope execute_timer(isolate->counters()->execute(),
isolate->counters()->execute()); isolate);
auto self = Utils::OpenHandle(this); auto self = Utils::OpenHandle(this);
STATIC_ASSERT(sizeof(v8::Local<v8::Value>) == sizeof(i::Handle<i::Object>)); STATIC_ASSERT(sizeof(v8::Local<v8::Value>) == sizeof(i::Handle<i::Object>));
bool should_set_has_no_side_effect = bool should_set_has_no_side_effect =
...@@ -5291,8 +5291,8 @@ MaybeLocal<v8::Value> Function::Call(Local<Context> context, ...@@ -5291,8 +5291,8 @@ MaybeLocal<v8::Value> Function::Call(Local<Context> context,
ENTER_V8(isolate, context, Function, Call, MaybeLocal<Value>(), ENTER_V8(isolate, context, Function, Call, MaybeLocal<Value>(),
InternalEscapableScope); InternalEscapableScope);
i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate); i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate);
i::LongTaskNestedTimedHistogramScope execute_timer( i::NestedTimedHistogramScope execute_timer(isolate->counters()->execute(),
isolate->counters()->execute()); isolate);
auto self = Utils::OpenHandle(this); auto self = Utils::OpenHandle(this);
Utils::ApiCheck(!self.is_null(), "v8::Function::Call", Utils::ApiCheck(!self.is_null(), "v8::Function::Call",
"Function to be called is a null pointer"); "Function to be called is a null pointer");
...@@ -6422,8 +6422,6 @@ Local<Context> NewContext( ...@@ -6422,8 +6422,6 @@ Local<Context> NewContext(
TRACE_EVENT_CALL_STATS_SCOPED(isolate, "v8", "V8.NewContext"); TRACE_EVENT_CALL_STATS_SCOPED(isolate, "v8", "V8.NewContext");
LOG_API(isolate, Context, New); LOG_API(isolate, Context, New);
i::LongTaskNestedTimedHistogramScope execute_timer(
isolate->counters()->execute());
i::HandleScope scope(isolate); i::HandleScope scope(isolate);
ExtensionConfiguration no_extensions; ExtensionConfiguration no_extensions;
if (extensions == nullptr) extensions = &no_extensions; if (extensions == nullptr) extensions = &no_extensions;
......
...@@ -12,7 +12,6 @@ ...@@ -12,7 +12,6 @@
#include "src/execution/isolate-inl.h" #include "src/execution/isolate-inl.h"
#include "src/execution/messages.h" #include "src/execution/messages.h"
#include "src/heap/factory.h" #include "src/heap/factory.h"
#include "src/logging/counters-scopes.h"
#include "src/logging/runtime-call-stats-scope.h" #include "src/logging/runtime-call-stats-scope.h"
#include "src/objects/api-callbacks.h" #include "src/objects/api-callbacks.h"
#include "src/objects/contexts.h" #include "src/objects/contexts.h"
...@@ -167,8 +166,6 @@ void Accessors::ArrayLengthSetter( ...@@ -167,8 +166,6 @@ void Accessors::ArrayLengthSetter(
const v8::PropertyCallbackInfo<v8::Boolean>& info) { const v8::PropertyCallbackInfo<v8::Boolean>& info) {
i::Isolate* isolate = reinterpret_cast<i::Isolate*>(info.GetIsolate()); i::Isolate* isolate = reinterpret_cast<i::Isolate*>(info.GetIsolate());
RCS_SCOPE(isolate, RuntimeCallCounterId::kArrayLengthSetter); RCS_SCOPE(isolate, RuntimeCallCounterId::kArrayLengthSetter);
i::LongTaskNestedTimedHistogramScope timer_scope(
isolate->counters()->execute());
HandleScope scope(isolate); HandleScope scope(isolate);
DCHECK(Utils::OpenHandle(*name)->SameValue( DCHECK(Utils::OpenHandle(*name)->SameValue(
......
...@@ -1070,21 +1070,21 @@ class V8_EXPORT_PRIVATE Isolate final : private HiddenFactory { ...@@ -1070,21 +1070,21 @@ class V8_EXPORT_PRIVATE Isolate final : private HiddenFactory {
NATIVE_CONTEXT_FIELDS(NATIVE_CONTEXT_FIELD_ACCESSOR) NATIVE_CONTEXT_FIELDS(NATIVE_CONTEXT_FIELD_ACCESSOR)
#undef NATIVE_CONTEXT_FIELD_ACCESSOR #undef NATIVE_CONTEXT_FIELD_ACCESSOR
Bootstrapper* bootstrapper() const { return bootstrapper_; } Bootstrapper* bootstrapper() { return bootstrapper_; }
// Use for updating counters on a foreground thread. // Use for updating counters on a foreground thread.
Counters* counters() const { return async_counters().get(); } Counters* counters() { return async_counters().get(); }
// Use for updating counters on a background thread. // Use for updating counters on a background thread.
const std::shared_ptr<Counters>& async_counters() const { const std::shared_ptr<Counters>& async_counters() {
// Make sure InitializeCounters() has been called. // Make sure InitializeCounters() has been called.
DCHECK_NOT_NULL(async_counters_.get()); DCHECK_NOT_NULL(async_counters_.get());
return async_counters_; return async_counters_;
} }
const std::shared_ptr<metrics::Recorder>& metrics_recorder() const { const std::shared_ptr<metrics::Recorder>& metrics_recorder() {
return metrics_recorder_; return metrics_recorder_;
} }
RuntimeProfiler* runtime_profiler() const { return runtime_profiler_; } RuntimeProfiler* runtime_profiler() { return runtime_profiler_; }
CompilationCache* compilation_cache() const { return compilation_cache_; } CompilationCache* compilation_cache() { return compilation_cache_; }
Logger* logger() const { Logger* logger() {
// Call InitializeLoggingAndCounters() if logging is needed before // Call InitializeLoggingAndCounters() if logging is needed before
// the isolate is fully initialized. // the isolate is fully initialized.
DCHECK_NOT_NULL(logger_); DCHECK_NOT_NULL(logger_);
......
...@@ -119,13 +119,9 @@ class V8_NODISCARD LazyTimedHistogramScope : public BaseTimedHistogramScope { ...@@ -119,13 +119,9 @@ class V8_NODISCARD LazyTimedHistogramScope : public BaseTimedHistogramScope {
// Helper class for scoping a NestedHistogramTimer. // Helper class for scoping a NestedHistogramTimer.
class V8_NODISCARD NestedTimedHistogramScope : public BaseTimedHistogramScope { class V8_NODISCARD NestedTimedHistogramScope : public BaseTimedHistogramScope {
public: public:
enum class LongTaskRecordMode { kSkip, kRecord }; explicit NestedTimedHistogramScope(NestedTimedHistogram* histogram,
Isolate* isolate = nullptr)
explicit NestedTimedHistogramScope( : BaseTimedHistogramScope(histogram), isolate_(isolate) {
NestedTimedHistogram* histogram,
LongTaskRecordMode long_task_record_mode = LongTaskRecordMode::kSkip)
: BaseTimedHistogramScope(histogram),
long_task_record_mode_(long_task_record_mode) {
Start(); Start();
} }
~NestedTimedHistogramScope() { Stop(); } ~NestedTimedHistogramScope() { Stop(); }
...@@ -134,36 +130,19 @@ class V8_NODISCARD NestedTimedHistogramScope : public BaseTimedHistogramScope { ...@@ -134,36 +130,19 @@ class V8_NODISCARD NestedTimedHistogramScope : public BaseTimedHistogramScope {
friend NestedTimedHistogram; friend NestedTimedHistogram;
friend PauseNestedTimedHistogramScope; friend PauseNestedTimedHistogramScope;
V8_INLINE void Start() { void StartInteral() {
if (histogram_->Enabled()) StartInteral();
LogStart(isolate());
}
V8_NOINLINE void StartInteral() {
previous_scope_ = timed_histogram()->Enter(this); previous_scope_ = timed_histogram()->Enter(this);
base::TimeTicks now = base::TimeTicks::HighResolutionNow(); base::TimeTicks now = base::TimeTicks::HighResolutionNow();
if (previous_scope_) previous_scope_->Pause(now); if (previous_scope_) previous_scope_->Pause(now);
timer_.Start(now); timer_.Start(now);
} }
void Pause(base::TimeTicks now) { void StopInternal() {
DCHECK(histogram_->Enabled());
timer_.Pause(now);
}
V8_INLINE void Stop() {
if (histogram_->Enabled()) StopInternal();
LogEnd(isolate());
}
V8_NOINLINE void StopInternal() {
timed_histogram()->Leave(previous_scope_); timed_histogram()->Leave(previous_scope_);
base::TimeTicks now = base::TimeTicks::HighResolutionNow(); base::TimeTicks now = base::TimeTicks::HighResolutionNow();
base::TimeDelta elapsed = timer_.Elapsed(now); base::TimeDelta elapsed = timer_.Elapsed(now);
histogram_->AddTimedSample(elapsed); histogram_->AddTimedSample(elapsed);
if (long_task_record_mode_ == LongTaskRecordMode::kRecord) { if (isolate_) RecordLongTaskTime(elapsed);
RecordLongTaskTime(elapsed);
}
#ifdef DEBUG #ifdef DEBUG
// StopInternal() is called in the destructor and don't access timer_ // StopInternal() is called in the destructor and don't access timer_
// after that. // after that.
...@@ -172,33 +151,39 @@ class V8_NODISCARD NestedTimedHistogramScope : public BaseTimedHistogramScope { ...@@ -172,33 +151,39 @@ class V8_NODISCARD NestedTimedHistogramScope : public BaseTimedHistogramScope {
if (previous_scope_) previous_scope_->Resume(now); if (previous_scope_) previous_scope_->Resume(now);
} }
V8_INLINE void Start() {
if (histogram_->Enabled()) StartInteral();
LogStart(timed_histogram()->counters()->isolate());
}
V8_INLINE void Stop() {
if (histogram_->Enabled()) StopInternal();
LogEnd(timed_histogram()->counters()->isolate());
}
void Pause(base::TimeTicks now) {
DCHECK(histogram_->Enabled());
timer_.Pause(now);
}
void Resume(base::TimeTicks now) { void Resume(base::TimeTicks now) {
DCHECK(histogram_->Enabled()); DCHECK(histogram_->Enabled());
timer_.Resume(now); timer_.Resume(now);
} }
void RecordLongTaskTime(base::TimeDelta elapsed) const { void RecordLongTaskTime(base::TimeDelta elapsed) const {
if (histogram_ == timed_histogram()->counters()->execute()) { if (histogram_ == isolate_->counters()->execute()) {
isolate()->GetCurrentLongTaskStats()->v8_execute_us += isolate_->GetCurrentLongTaskStats()->v8_execute_us +=
elapsed.InMicroseconds(); elapsed.InMicroseconds();
} }
} }
Isolate* isolate() const { return timed_histogram()->counters()->isolate(); } NestedTimedHistogram* timed_histogram() {
NestedTimedHistogram* timed_histogram() const {
return static_cast<NestedTimedHistogram*>(histogram_); return static_cast<NestedTimedHistogram*>(histogram_);
} }
NestedTimedHistogramScope* previous_scope_; NestedTimedHistogramScope* previous_scope_;
LongTaskRecordMode long_task_record_mode_; Isolate* isolate_;
};
class V8_NODISCARD LongTaskNestedTimedHistogramScope
: public NestedTimedHistogramScope {
public:
explicit LongTaskNestedTimedHistogramScope(NestedTimedHistogram* histogram)
: NestedTimedHistogramScope(histogram, LongTaskRecordMode::kRecord) {}
}; };
// Temporarily pause a NestedTimedHistogram when for instance leaving V8 for // Temporarily pause a NestedTimedHistogram when for instance leaving V8 for
...@@ -207,32 +192,20 @@ class V8_NODISCARD PauseNestedTimedHistogramScope { ...@@ -207,32 +192,20 @@ class V8_NODISCARD PauseNestedTimedHistogramScope {
public: public:
explicit PauseNestedTimedHistogramScope(NestedTimedHistogram* histogram) explicit PauseNestedTimedHistogramScope(NestedTimedHistogram* histogram)
: histogram_(histogram) { : histogram_(histogram) {
if (isEnabled()) Pause();
}
~PauseNestedTimedHistogramScope() {
if (isEnabled()) Resume();
}
private:
bool isEnabled() const { return previous_scope_ && histogram_->Enabled(); }
V8_NOINLINE void Pause() {
previous_scope_ = histogram_->Enter(nullptr); previous_scope_ = histogram_->Enter(nullptr);
// For performance reasons we don't annotate all internal callbacks with if (isEnabled()) {
// NestedTimerScopes which might lead to double pausing and minor
// inaccuracies.
// TODO(v8:12498): Add DCHECK_NOT_NULL(previous_scope_)
if (previous_scope_) {
previous_scope_->Pause(base::TimeTicks::HighResolutionNow()); previous_scope_->Pause(base::TimeTicks::HighResolutionNow());
} }
} }
~PauseNestedTimedHistogramScope() {
V8_NOINLINE void Resume() {
histogram_->Leave(previous_scope_); histogram_->Leave(previous_scope_);
previous_scope_->Resume(base::TimeTicks::HighResolutionNow()); if (isEnabled()) {
previous_scope_->Resume(base::TimeTicks::HighResolutionNow());
}
} }
private:
bool isEnabled() const { return previous_scope_ && histogram_->Enabled(); }
NestedTimedHistogram* histogram_; NestedTimedHistogram* histogram_;
NestedTimedHistogramScope* previous_scope_; NestedTimedHistogramScope* previous_scope_;
}; };
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment