Commit ddf4690d authored by Greg Kraynov's avatar Greg Kraynov Committed by Commit Bot

Blink Scheduler: Trace main thread task types.

Change-Id: If4cb73bc28300b5ed01ce10f7068ff930c8ba6cb
Reviewed-on: https://chromium-review.googlesource.com/847482
Commit-Queue: Greg Kraynov <kraynov@chromium.org>
Reviewed-by: default avatarAlexander Timin <altimin@chromium.org>
Cr-Commit-Position: refs/heads/master@{#527108}
parent 263d53ca
...@@ -116,6 +116,76 @@ bool StopLoadingInBackgroundEnabled() { ...@@ -116,6 +116,76 @@ bool StopLoadingInBackgroundEnabled() {
return RuntimeEnabledFeatures::StopLoadingInBackgroundEnabled(); return RuntimeEnabledFeatures::StopLoadingInBackgroundEnabled();
} }
const char* TaskTypeToString(TaskType task_type) {
switch (task_type) {
case TaskType::kDOMManipulation:
return "DOMManipultion";
case TaskType::kUserInteraction:
return "UserInteraction";
case TaskType::kNetworking:
return "Networking";
case TaskType::kNetworkingControl:
return "NetworkingControl";
case TaskType::kHistoryTraversal:
return "HistoryTraversal";
case TaskType::kEmbed:
return "Embed";
case TaskType::kMediaElementEvent:
return "MediaElementEvent";
case TaskType::kCanvasBlobSerialization:
return "CanvasBlobSerialization";
case TaskType::kMicrotask:
return "Microtask";
case TaskType::kJavascriptTimer:
return "JavascriptTimer";
case TaskType::kRemoteEvent:
return "RemoteEvent";
case TaskType::kWebSocket:
return "WebSocket";
case TaskType::kPostedMessage:
return "PostedMessage";
case TaskType::kUnshippedPortMessage:
return "UnshipedPortMessage";
case TaskType::kFileReading:
return "FileReading";
case TaskType::kDatabaseAccess:
return "DatabaseAccess";
case TaskType::kPresentation:
return "Presentation";
case TaskType::kSensor:
return "Sensor";
case TaskType::kPerformanceTimeline:
return "PerformanceTimeline";
case TaskType::kWebGL:
return "WebGL";
case TaskType::kIdleTask:
return "IdleTask";
case TaskType::kMiscPlatformAPI:
return "MiscPlatformAPI";
case TaskType::kUnspecedTimer:
return "UnspecedTimer";
case TaskType::kUnspecedLoading:
return "UnspecedLoading";
case TaskType::kUnthrottled:
return "Unthrottled";
case TaskType::kInternalTest:
return "InternalTest";
case TaskType::kCount:
return "Count";
}
NOTREACHED();
return "";
}
const char* OptionalTaskDescriptionToString(
base::Optional<RendererSchedulerImpl::TaskDescriptionForTracing> opt_desc) {
if (!opt_desc)
return nullptr;
if (opt_desc->task_type)
return TaskTypeToString(opt_desc->task_type.value());
return MainThreadTaskQueue::NameForQueueType(opt_desc->queue_type);
}
} // namespace } // namespace
RendererSchedulerImpl::RendererSchedulerImpl( RendererSchedulerImpl::RendererSchedulerImpl(
...@@ -374,6 +444,10 @@ RendererSchedulerImpl::MainThreadOnly::MainThreadOnly( ...@@ -374,6 +444,10 @@ RendererSchedulerImpl::MainThreadOnly::MainThreadOnly(
"RendererScheduler.ProcessType", "RendererScheduler.ProcessType",
renderer_scheduler_impl, renderer_scheduler_impl,
RendererProcessTypeToString), RendererProcessTypeToString),
task_description_for_tracing(base::nullopt,
"RendererScheduler.MainThreadTask",
renderer_scheduler_impl,
OptionalTaskDescriptionToString),
virtual_time_policy(VirtualTimePolicy::kAdvance), virtual_time_policy(VirtualTimePolicy::kAdvance),
virtual_time_pause_count(0), virtual_time_pause_count(0),
max_virtual_time_task_starvation_count(0), max_virtual_time_task_starvation_count(0),
...@@ -2272,6 +2346,8 @@ void RendererSchedulerImpl::OnTaskStarted(MainThreadTaskQueue* queue, ...@@ -2272,6 +2346,8 @@ void RendererSchedulerImpl::OnTaskStarted(MainThreadTaskQueue* queue,
seqlock_queueing_time_estimator_.seqlock.WriteBegin(); seqlock_queueing_time_estimator_.seqlock.WriteBegin();
seqlock_queueing_time_estimator_.data.OnTopLevelTaskStarted(start, queue); seqlock_queueing_time_estimator_.data.OnTopLevelTaskStarted(start, queue);
seqlock_queueing_time_estimator_.seqlock.WriteEnd(); seqlock_queueing_time_estimator_.seqlock.WriteEnd();
main_thread_only().task_description_for_tracing =
TaskDescriptionForTracing{task.task_type(), queue->queue_type()};
} }
void RendererSchedulerImpl::OnTaskCompleted(MainThreadTaskQueue* queue, void RendererSchedulerImpl::OnTaskCompleted(MainThreadTaskQueue* queue,
...@@ -2287,6 +2363,7 @@ void RendererSchedulerImpl::OnTaskCompleted(MainThreadTaskQueue* queue, ...@@ -2287,6 +2363,7 @@ void RendererSchedulerImpl::OnTaskCompleted(MainThreadTaskQueue* queue,
// TODO(altimin): Per-page metrics should also be considered. // TODO(altimin): Per-page metrics should also be considered.
main_thread_only().metrics_helper.RecordTaskMetrics(queue, task, start, end); main_thread_only().metrics_helper.RecordTaskMetrics(queue, task, start, end);
main_thread_only().task_description_for_tracing = base::nullopt;
} }
void RendererSchedulerImpl::OnBeginNestedRunLoop() { void RendererSchedulerImpl::OnBeginNestedRunLoop() {
...@@ -2432,6 +2509,7 @@ void RendererSchedulerImpl::OnTraceLogEnabled() { ...@@ -2432,6 +2509,7 @@ void RendererSchedulerImpl::OnTraceLogEnabled() {
main_thread_only().has_navigated.OnTraceLogEnabled(); main_thread_only().has_navigated.OnTraceLogEnabled();
main_thread_only().pause_timers_for_webview.OnTraceLogEnabled(); main_thread_only().pause_timers_for_webview.OnTraceLogEnabled();
main_thread_only().process_type.OnTraceLogEnabled(); main_thread_only().process_type.OnTraceLogEnabled();
main_thread_only().task_description_for_tracing.OnTraceLogEnabled();
for (WebViewSchedulerImpl* web_view_scheduler : for (WebViewSchedulerImpl* web_view_scheduler :
main_thread_only().web_view_schedulers) { main_thread_only().web_view_schedulers) {
......
...@@ -90,6 +90,18 @@ class PLATFORM_EXPORT RendererSchedulerImpl ...@@ -90,6 +90,18 @@ class PLATFORM_EXPORT RendererSchedulerImpl
kUseCaseCount, kUseCaseCount,
kFirstUseCase = kNone, kFirstUseCase = kNone,
}; };
// Don't use except for tracing.
struct TaskDescriptionForTracing {
base::Optional<TaskType> task_type;
MainThreadTaskQueue::QueueType queue_type;
// Required in order to wrap in TraceableState.
constexpr bool operator!=(const TaskDescriptionForTracing& rhs) const {
return task_type != rhs.task_type || queue_type != rhs.queue_type;
}
};
static const char* UseCaseToString(UseCase use_case); static const char* UseCaseToString(UseCase use_case);
static const char* RAILModeToString(v8::RAILMode rail_mode); static const char* RAILModeToString(v8::RAILMode rail_mode);
static const char* VirtualTimePolicyToString( static const char* VirtualTimePolicyToString(
...@@ -682,6 +694,9 @@ class PLATFORM_EXPORT RendererSchedulerImpl ...@@ -682,6 +694,9 @@ class PLATFORM_EXPORT RendererSchedulerImpl
RendererMetricsHelper metrics_helper; RendererMetricsHelper metrics_helper;
TraceableState<RendererProcessType, kTracingCategoryNameDefault> TraceableState<RendererProcessType, kTracingCategoryNameDefault>
process_type; process_type;
TraceableState<base::Optional<TaskDescriptionForTracing>,
kTracingCategoryNameInfo>
task_description_for_tracing; // Don't use except for tracing.
base::ObserverList<VirtualTimeObserver> virtual_time_observers; base::ObserverList<VirtualTimeObserver> virtual_time_observers;
base::TimeTicks initial_virtual_time; base::TimeTicks initial_virtual_time;
VirtualTimePolicy virtual_time_policy; VirtualTimePolicy virtual_time_policy;
......
...@@ -52,13 +52,13 @@ class TraceableState { ...@@ -52,13 +52,13 @@ class TraceableState {
object_(object), object_(object),
converter_(converter), converter_(converter),
state_(initial_state), state_(initial_state),
started_(false) { slice_is_open_(false) {
internal::ValidateTracingCategory(category); internal::ValidateTracingCategory(category);
Trace(); Trace();
} }
~TraceableState() { ~TraceableState() {
if (started_) if (slice_is_open_)
TRACE_EVENT_ASYNC_END0(category, name_, object_); TRACE_EVENT_ASYNC_END0(category, name_, object_);
} }
...@@ -91,18 +91,24 @@ class TraceableState { ...@@ -91,18 +91,24 @@ class TraceableState {
} }
void Trace() { void Trace() {
if (started_) if (slice_is_open_) {
TRACE_EVENT_ASYNC_END0(category, name_, object_); TRACE_EVENT_ASYNC_END0(category, name_, object_);
slice_is_open_ = false;
started_ = is_enabled();
if (started_) {
// Trace viewer logic relies on subslice starting at the exact same time
// as the async event.
base::TimeTicks now = base::TimeTicks::Now();
TRACE_EVENT_ASYNC_BEGIN_WITH_TIMESTAMP0(category, name_, object_, now);
TRACE_EVENT_ASYNC_STEP_INTO_WITH_TIMESTAMP0(category, name_, object_,
converter_(state_), now);
} }
if (!is_enabled())
return;
// Converter returns nullptr to indicate the absence of state.
const char* state_str = converter_(state_);
if (!state_str)
return;
// Trace viewer logic relies on subslice starting at the exact same time
// as the async event.
base::TimeTicks now = base::TimeTicks::Now();
TRACE_EVENT_ASYNC_BEGIN_WITH_TIMESTAMP0(category, name_, object_, now);
TRACE_EVENT_ASYNC_STEP_INTO_WITH_TIMESTAMP0(category, name_, object_,
state_str, now);
slice_is_open_ = true;
} }
bool is_enabled() const { bool is_enabled() const {
...@@ -116,9 +122,9 @@ class TraceableState { ...@@ -116,9 +122,9 @@ class TraceableState {
const ConverterFuncPtr converter_; const ConverterFuncPtr converter_;
T state_; T state_;
// We have to track |started_| state to avoid race condition since SetState // We have to track whether slice is open to avoid confusion since assignment,
// might be called before OnTraceLogEnabled notification. // "absent" state and OnTraceLogEnabled can happen anytime.
bool started_; bool slice_is_open_;
DISALLOW_COPY(TraceableState); DISALLOW_COPY(TraceableState);
}; };
......
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