Commit 3a6e3da4 authored by Francois Doray's avatar Francois Doray Committed by Commit Bot

[threadpool] Remove ThreadPool.TaskLatencyMicroseconds.* histograms.

Fixed: 1089866, 1089865, 1089864, 1046191, 972892
Bug: 1089866, 1089865, 1089864, 1046191, 972892
Change-Id: I60e2ad08e3f0ea5dd676a00d61338aa47c2d4aca
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2510770Reviewed-by: default avatarAlexander Timin <altimin@chromium.org>
Reviewed-by: default avatarEtienne Pierre-Doray <etiennep@chromium.org>
Commit-Queue: François Doray <fdoray@chromium.org>
Cr-Commit-Position: refs/heads/master@{#823314}
parent df9e3cc5
......@@ -194,3 +194,141 @@ Date: October 2020
| 50 | 362 | 418 |
| 75 | 1161 | 1307 |
| 95 | > 1 hour | > 1 hour |
## Task Latency
Time elapsed between when a task is posted and when it starts to run. Recorded
for each task that runs inside the ThreadPool.
Unit: microseconds
Histogram name: ThreadPool.TaskLatencyMicroseconds.(Browser/Renderer).(UserBlocking/UserVisible/Background)TaskPriority
Date: October 13, 2020
### Windows
#### Browser process
| Percentile | USER_BLOCKING | USER_VISIBLE | BEST_EFFORT |
|------------|---------------|--------------|-------------|
| 25 | 11 | 13 | 39 |
| 50 | 19 | 27 | 386 |
| 75 | 44 | 60 | 2533 |
| 95 | 495 | 701 | > 20 ms |
| 99 | > 20 ms | 16705 | > 20 ms |
Count distribution:
- USER_BLOCKING: 14%
- USER_VISIBLE: 72%
- BEST_EFFORT: 14%
#### Renderer process
| Percentile | USER_BLOCKING | USER_VISIBLE | BEST_EFFORT |
|------------|---------------|--------------|-------------|
| 25 | 14 | 18 | 151 |
| 50 | 30 | 39 | 567 |
| 75 | 65 | 86 | 9145 |
| 95 | 1102 | 2230 | > 20 ms |
| 99 | 7664 | > 20 ms | > 20 ms |
Count distribution:
- USER_BLOCKING: 45%
- USER_VISIBLE: 54%
- BEST_EFFORT: 0%
### Mac
#### Browser process
| Percentile | USER_BLOCKING | USER_VISIBLE | BEST_EFFORT |
|------------|---------------|--------------|-------------|
| 25 | 15 | 15 | 1748 |
| 50 | 28 | 32 | 4848 |
| 75 | 99 | 90 | 12492 |
| 95 | 2101 | 1781 | > 20 ms |
| 99 | 13129 | 17192 | > 20 ms |
Count distribution:
- USER_BLOCKING: 13%
- USER_VISIBLE: 81%
- BEST_EFFORT: 6%
#### Renderer process
| Percentile | USER_BLOCKING | USER_VISIBLE | BEST_EFFORT |
|------------|---------------|--------------|-------------|
| 25 | 15 | 22 | 108 |
| 50 | 28 | 36 | 175 |
| 75 | 66 | 58 | 1783 |
| 95 | 630 | 684 | > 20 ms |
| 99 | 3895 | 6966 | > 20 ms |
Count distribution:
- USER_BLOCKING: 45%
- USER_VISIBLE: 55%
- BEST_EFFORT: 0%
### Chrome OS
#### Browser process
| Percentile | USER_BLOCKING | USER_VISIBLE | BEST_EFFORT |
|------------|---------------|--------------|-------------|
| 25 | 38 | 23 | 17 |
| 50 | 68 | 65 | 28 |
| 75 | 218 | 198 | 613 |
| 95 | 2293 | 3615 | > 20 ms |
| 99 | 18084 | > 20 ms | > 20 ms |
Count distribution:
- USER_BLOCKING: 7%
- USER_VISIBLE: 40%
- BEST_EFFORT: 53%
#### Renderer process
| Percentile | USER_BLOCKING | USER_VISIBLE | BEST_EFFORT |
|------------|---------------|--------------|-------------|
| 25 | 40 | 48 | 74 |
| 50 | 111 | 108 | 484 |
| 75 | 496 | 628 | > 20 ms |
| 95 | 5394 | 5866 | > 20 ms |
| 99 | > 20 ms | > 20 ms | > 20 ms |
Count distribution:
- USER_BLOCKING: 68%
- USER_VISIBLE: 32%
- BEST_EFFORT: 0%
### Android
#### Browser process
| Percentile | USER_BLOCKING | USER_VISIBLE | BEST_EFFORT |
|------------|---------------|--------------|-------------|
| 25 | 43 | 37 | 53 |
| 50 | 86 | 103 | 122 |
| 75 | 224 | 412 | 648 |
| 95 | 1719 | > 20 ms | > 20 ms |
| 99 | 10001 | > 20 ms | > 20 ms |
Count distribution:
- USER_BLOCKING: 58%
- USER_VISIBLE: 39%
- BEST_EFFORT: 4%
#### Renderer process
| Percentile | USER_BLOCKING | USER_VISIBLE | BEST_EFFORT |
|------------|---------------|--------------|-------------|
| 25 | 45 | 63 | 72 |
| 50 | 90 | 109 | 115 |
| 75 | 242 | 246 | 235 |
| 95 | 1635 | 960 | 829 |
| 99 | 6728 | 3273 | 3273 |
Count distribution:
- USER_BLOCKING: 35%
- USER_VISIBLE: 63%
- BEST_EFFORT: 2%
......@@ -297,15 +297,6 @@ TaskTracker::TaskTracker(StringPiece histogram_label)
can_run_policy_(CanRunPolicy::kAll),
flush_cv_(flush_lock_.CreateConditionVariable()),
shutdown_lock_(&flush_lock_),
task_latency_histograms_{GetLatencyHistogram("TaskLatencyMicroseconds",
histogram_label,
"BackgroundTaskPriority"),
GetLatencyHistogram("TaskLatencyMicroseconds",
histogram_label,
"UserVisibleTaskPriority"),
GetLatencyHistogram("TaskLatencyMicroseconds",
histogram_label,
"UserBlockingTaskPriority")},
heartbeat_latency_histograms_{
GetLatencyHistogram("HeartbeatLatencyMicroseconds",
histogram_label,
......@@ -492,16 +483,6 @@ bool TaskTracker::IsShutdownComplete() const {
return shutdown_event_ && shutdown_event_->IsSignaled();
}
void TaskTracker::RecordLatencyHistogram(TaskPriority priority,
TimeTicks posted_time) const {
if (histogram_label_.empty())
return;
const TimeDelta task_latency = TimeTicks::Now() - posted_time;
GetHistogramForTaskPriority(priority, task_latency_histograms_)
->AddTimeMicrosecondsGranularity(task_latency);
}
void TaskTracker::RecordHeartbeatLatencyHistogram(TaskPriority priority,
TimeTicks posted_time) const {
if (histogram_label_.empty())
......@@ -516,7 +497,6 @@ void TaskTracker::RunTask(Task task,
TaskSource* task_source,
const TaskTraits& traits) {
DCHECK(task_source);
RecordLatencyHistogram(traits.priority(), task.queue_time);
const auto environment = task_source->GetExecutionEnvironment();
......
......@@ -194,11 +194,6 @@ class BASE_EXPORT TaskTracker {
// manner.
void CallFlushCallbackForTesting();
// Records |Now() - posted_time| to the
// ThreadPool.TaskLatencyMicroseconds.[label].[priority] histogram.
void RecordLatencyHistogram(TaskPriority priority,
TimeTicks posted_time) const;
// Dummy frames to allow identification of shutdown behavior in a stack trace.
void RunContinueOnShutdown(Task* task);
void RunSkipOnShutdown(Task* task);
......@@ -254,16 +249,12 @@ class BASE_EXPORT TaskTracker {
// completes.
std::unique_ptr<WaitableEvent> shutdown_event_ GUARDED_BY(shutdown_lock_);
// ThreadPool.TaskLatencyMicroseconds.*,
// ThreadPool.HeartbeatLatencyMicroseconds.*, and
// ThreadPool.NumTasksRunWhileQueuing.* histograms. The index is a
// ThreadPool.HeartbeatLatencyMicroseconds.* histograms. The index is a
// TaskPriority. Intentionally leaked.
// TODO(scheduler-dev): Consider using STATIC_HISTOGRAM_POINTER_GROUP for
// these.
// TODO(scheduler-dev): Consider using STATIC_HISTOGRAM_POINTER_GROUP.
using TaskPriorityType = std::underlying_type<TaskPriority>::type;
static constexpr TaskPriorityType kNumTaskPriorities =
static_cast<TaskPriorityType>(TaskPriority::HIGHEST) + 1;
HistogramBase* const task_latency_histograms_[kNumTaskPriorities];
HistogramBase* const heartbeat_latency_histograms_[kNumTaskPriorities];
// Ensures all state (e.g. dangling cleaned up workers) is coalesced before
......
......@@ -1230,54 +1230,5 @@ TEST(ThreadPoolTaskTrackerWaitAllowedTest, WaitAllowed) {
wait_allowed_test_thread.Join();
}
// Verify that ThreadPool.TaskLatency.* histograms are correctly recorded
// when a task runs.
TEST(ThreadPoolTaskTrackerHistogramTest, TaskLatency) {
TaskTracker tracker("Test");
struct {
const TaskTraits traits;
const char* const expected_histogram;
} static constexpr kTests[] = {
{{TaskPriority::BEST_EFFORT},
"ThreadPool.TaskLatencyMicroseconds.Test."
"BackgroundTaskPriority"},
{{MayBlock(), TaskPriority::BEST_EFFORT},
"ThreadPool.TaskLatencyMicroseconds.Test."
"BackgroundTaskPriority"},
{{WithBaseSyncPrimitives(), TaskPriority::BEST_EFFORT},
"ThreadPool.TaskLatencyMicroseconds.Test."
"BackgroundTaskPriority"},
{{TaskPriority::USER_VISIBLE},
"ThreadPool.TaskLatencyMicroseconds.Test."
"UserVisibleTaskPriority"},
{{MayBlock(), TaskPriority::USER_VISIBLE},
"ThreadPool.TaskLatencyMicroseconds.Test."
"UserVisibleTaskPriority"},
{{WithBaseSyncPrimitives(), TaskPriority::USER_VISIBLE},
"ThreadPool.TaskLatencyMicroseconds.Test."
"UserVisibleTaskPriority"},
{{TaskPriority::USER_BLOCKING},
"ThreadPool.TaskLatencyMicroseconds.Test."
"UserBlockingTaskPriority"},
{{MayBlock(), TaskPriority::USER_BLOCKING},
"ThreadPool.TaskLatencyMicroseconds.Test."
"UserBlockingTaskPriority"},
{{WithBaseSyncPrimitives(), TaskPriority::USER_BLOCKING},
"ThreadPool.TaskLatencyMicroseconds.Test."
"UserBlockingTaskPriority"}};
for (const auto& test : kTests) {
Task task(FROM_HERE, DoNothing(), TimeDelta());
ASSERT_TRUE(tracker.WillPostTask(&task, test.traits.shutdown_behavior()));
HistogramTester tester;
test::QueueAndRunTaskSource(
&tracker, test::CreateSequenceWithTask(std::move(task), test.traits));
tester.ExpectTotalCount(test.expected_histogram, 1);
}
}
} // namespace internal
} // namespace base
......@@ -376,6 +376,9 @@ reviews. Googlers can read more about this at go/gwsq-gerrit.
<histogram base="true" name="ThreadPool.TaskLatencyMicroseconds"
units="microseconds" expires_after="M85">
<obsolete>
Removed 10/2020. Not actively used.
</obsolete>
<owner>fdoray@chromium.org</owner>
<owner>gab@chromium.org</owner>
<owner>robliao@chromium.org</owner>
......
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