[wasm] Skip low-resolution time samples

In multiple counters we have peaks in the 0 microseconds and 1000
microseconds bucket, most probably coming from clients with a
low-resolution clock. Exclude those to get more precise timings.

R=jkummerow@chromium.org

Change-Id: I9b8377354920db4d0070198f440b57a7e86dc7bd
Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/3902221
Reviewed-by: Jakob Kummerow <jkummerow@chromium.org>
Commit-Queue: Clemens Backes <clemensb@chromium.org>
Cr-Commit-Position: refs/heads/main@{#83276}
This commit is contained in:
Clemens Backes 2022-09-16 14:49:26 +02:00 committed by V8 LUCI CQ
parent 45d4d220d2
commit 50504b168d
3 changed files with 31 additions and 18 deletions

View File

@ -66,7 +66,7 @@ WasmCompilationResult WasmCompilationUnit::ExecuteFunctionCompilation(
base::Optional<TimedHistogramScope> wasm_compile_function_time_scope;
base::Optional<TimedHistogramScope> wasm_compile_huge_function_time_scope;
if (counters) {
if (counters && base::TimeTicks::IsHighResolution()) {
if (func_body.end - func_body.start >= 100 * KB) {
auto huge_size_histogram = SELECT_WASM_COUNTER(
counters, env->module->origin, wasm, huge_function_size_bytes);

View File

@ -1997,8 +1997,11 @@ std::shared_ptr<NativeModule> CompileToNativeModule(
return native_module;
}
TimedHistogramScope wasm_compile_module_time_scope(SELECT_WASM_COUNTER(
isolate->counters(), wasm_module->origin, wasm_compile, module_time));
base::Optional<TimedHistogramScope> wasm_compile_module_time_scope;
if (base::TimeTicks::IsHighResolution()) {
wasm_compile_module_time_scope.emplace(SELECT_WASM_COUNTER(
isolate->counters(), wasm_module->origin, wasm_compile, module_time));
}
// Embedder usage count for declared shared memories.
if (wasm_module->has_shared_memory) {
@ -3052,9 +3055,11 @@ bool AsyncStreamingProcessor::Deserialize(
base::Vector<const uint8_t> module_bytes,
base::Vector<const uint8_t> wire_bytes) {
TRACE_EVENT0("v8.wasm", "wasm.Deserialize");
TimedHistogramScope time_scope(
job_->isolate()->counters()->wasm_deserialization_time(),
job_->isolate());
base::Optional<TimedHistogramScope> time_scope;
if (base::TimeTicks::IsHighResolution()) {
time_scope.emplace(job_->isolate()->counters()->wasm_deserialization_time(),
job_->isolate());
}
// DeserializeNativeModule and FinishCompile assume that they are executed in
// a HandleScope, and that a context is set on the isolate.
HandleScope scope(job_->isolate_);
@ -3297,8 +3302,11 @@ void CompilationStateImpl::InitializeCompilationProgressAfterDeserialization(
TRACE_EVENT2("v8.wasm", "wasm.CompilationAfterDeserialization",
"num_lazy_functions", lazy_functions.size(),
"num_eager_functions", eager_functions.size());
TimedHistogramScope lazy_compile_time_scope(
counters()->wasm_compile_after_deserialize());
base::Optional<TimedHistogramScope> lazy_compile_time_scope;
if (base::TimeTicks::IsHighResolution()) {
lazy_compile_time_scope.emplace(
counters()->wasm_compile_after_deserialize());
}
auto* module = native_module_->module();
base::Optional<CodeSpaceWriteScope> lazy_code_space_write_scope;

View File

@ -521,12 +521,12 @@ MaybeHandle<WasmInstanceObject> InstanceBuilder::Build() {
// From here on, we expect the build pipeline to run without exiting to JS.
DisallowJavascriptExecution no_js(isolate_);
// Record build time into correct bucket, then build instance.
TimedHistogramScope wasm_instantiate_module_time_scope(SELECT_WASM_COUNTER(
isolate_->counters(), module_->origin, wasm_instantiate, module_time));
v8::metrics::WasmModuleInstantiated wasm_module_instantiated;
// Start a timer for instantiation time, if we have a high resolution timer.
base::ElapsedTimer timer;
timer.Start();
if (base::TimeTicks::IsHighResolution()) {
timer.Start();
}
v8::metrics::WasmModuleInstantiated wasm_module_instantiated;
NativeModule* native_module = module_object_->native_module();
//--------------------------------------------------------------------------
@ -855,11 +855,16 @@ MaybeHandle<WasmInstanceObject> InstanceBuilder::Build() {
TRACE("Successfully built instance for module %p\n",
module_object_->native_module());
wasm_module_instantiated.success = true;
wasm_module_instantiated.wall_clock_duration_in_us =
timer.Elapsed().InMicroseconds();
timer.Stop();
isolate_->metrics_recorder()->DelayMainThreadEvent(wasm_module_instantiated,
context_id_);
if (timer.IsStarted()) {
base::TimeDelta instantiation_time = timer.Elapsed();
wasm_module_instantiated.wall_clock_duration_in_us =
instantiation_time.InMicroseconds();
SELECT_WASM_COUNTER(isolate_->counters(), module_->origin, wasm_instantiate,
module_time)
->AddTimedSample(instantiation_time);
isolate_->metrics_recorder()->DelayMainThreadEvent(wasm_module_instantiated,
context_id_);
}
return instance;
}