Commit 6e1f3ec8 authored by Chinglin Yu's avatar Chinglin Yu Committed by Commit Bot

Fix flakiness of profile_provider_unittest

This improves the stability of ProfileProviderRealCollectionTest suite
running on VM:

* Increase the default collection duration. Default colleciton duration
is doubled to 2 sec. Jankiness collection duration is increased from 0.5
sec. to 1.5 sec.
* Create a thread that spins the CPU during profile collection. This
ensures that the CPU cycles counter will move forward to trigger perf
collection.

Also improves error logging: on collection failure, log collection
failure reasons recorded in the UMA metric.

Bug: 1132045
Test: Run profile_provider_unittest on crosvm

Change-Id: I600ace7500144398bb7ed56ed80a75fcb1df1907
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2449509
Commit-Queue: Chinglin Yu <chinglinyu@chromium.org>
Reviewed-by: default avatarGabriel Marin <gmx@chromium.org>
Cr-Commit-Position: refs/heads/master@{#816048}
parent b4ba481b
......@@ -7,7 +7,9 @@
#include "base/bind.h"
#include "base/command_line.h"
#include "base/metrics/field_trial.h"
#include "base/metrics/statistics_recorder.h"
#include "base/run_loop.h"
#include "base/synchronization/waitable_event.h"
#include "base/test/bind_test_util.h"
#include "base/test/test_suite.h"
#include "base/timer/timer.h"
......@@ -24,8 +26,8 @@ namespace metrics {
const base::TimeDelta kPeriodicCollectionInterval =
base::TimeDelta::FromHours(1);
const base::TimeDelta kMaxCollectionDelay = base::TimeDelta::FromSeconds(1);
// Use non-default 1-sec collection duration to make the test run faster.
const base::TimeDelta kCollectionDuration = base::TimeDelta::FromSeconds(1);
// Use a 2-sec collection duration.
const base::TimeDelta kCollectionDuration = base::TimeDelta::FromSeconds(2);
// The timeout in waiting until collection done. 8 sec is a safe value far
// beyond the collection duration used.
const base::TimeDelta kCollectionDoneTimeout = base::TimeDelta::FromSeconds(8);
......@@ -151,9 +153,13 @@ class ProfileProviderRealCollectionTest : public testing::Test {
// Finishes Init() on the dedicated sequence.
task_environment_.RunUntilIdle();
StartSpinningCPU();
}
void TearDown() override {
StopSpinningCPU();
profile_provider_.reset();
chromeos::LoginState::Shutdown();
chromeos::PowerManagerClient::Shutdown();
......@@ -161,7 +167,65 @@ class ProfileProviderRealCollectionTest : public testing::Test {
variations::testing::ClearAllVariationParams();
}
void AssertProfileData(SampledProfile::TriggerEvent trigger_event) {
// Sets up a ScopedClosureRunner for logging extra information on assertion
// failure.
base::ScopedClosureRunner scoped_log_error(base::BindOnce([]() {
// Collection failed: log the failure in the UMA histogram.
auto* histogram =
base::StatisticsRecorder::FindHistogram("ChromeOS.CWP.CollectPerf");
if (!histogram) {
LOG(WARNING) << "Profile collection failed without "
"ChromeOS.CWP.CollectPerf histogram data";
return;
}
std::string histogram_ascii;
histogram->WriteAscii(&histogram_ascii);
LOG(ERROR) << "Profile collection result: " << histogram_ascii;
}));
std::vector<SampledProfile> stored_profiles;
ASSERT_TRUE(profile_provider_->GetSampledProfiles(&stored_profiles));
auto& profile = stored_profiles[0];
EXPECT_EQ(trigger_event, profile.trigger_event());
ASSERT_TRUE(profile.has_perf_data());
// Collection succeeded: don't output the error log.
ignore_result(scoped_log_error.Release());
}
protected:
// Spins the CPU to move forward the CPU cycles counter and makes sure the
// perf session always has samples to collect.
void StartSpinningCPU() {
spin_cpu_ = true;
spin_cpu_task_runner_ = base::ThreadPool::CreateSequencedTaskRunner({});
spin_cpu_task_runner_->PostTask(
FROM_HERE, base::BindOnce(
[](ProfileProviderRealCollectionTest* self) {
while (self->spin_cpu_) {
}
// Signal that this task is exiting and won't touch
// |this| anymore.
self->spin_cpu_done_.Signal();
},
base::Unretained(this)));
}
void StopSpinningCPU() {
spin_cpu_ = false;
// Wait until the current sequence is signaled that the CPU spinning task
// has finished execution so it doesn't use any data member of |this|.
if (!spin_cpu_done_.IsSignaled())
spin_cpu_done_.Wait();
spin_cpu_task_runner_ = nullptr;
}
// |task_environment_| must be the first member (or at least before
// any member that cares about tasks) to be initialized first and destroyed
// last.
......@@ -169,6 +233,10 @@ class ProfileProviderRealCollectionTest : public testing::Test {
scoped_refptr<base::FieldTrial> field_trial_;
scoped_refptr<base::SequencedTaskRunner> spin_cpu_task_runner_;
std::atomic_bool spin_cpu_{false};
base::WaitableEvent spin_cpu_done_;
std::unique_ptr<TestProfileProvider> profile_provider_;
DISALLOW_COPY_AND_ASSIGN(ProfileProviderRealCollectionTest);
......@@ -181,27 +249,17 @@ TEST_F(ProfileProviderRealCollectionTest, SuspendDone) {
profile_provider_->WaitUntilCollectionDone();
EXPECT_TRUE(profile_provider_->collection_done());
std::vector<SampledProfile> stored_profiles;
ASSERT_TRUE(profile_provider_->GetSampledProfiles(&stored_profiles));
auto& profile = stored_profiles[0];
EXPECT_EQ(SampledProfile::RESUME_FROM_SUSPEND, profile.trigger_event());
ASSERT_TRUE(profile.has_perf_data());
AssertProfileData(SampledProfile::RESUME_FROM_SUSPEND);
}
TEST_F(ProfileProviderRealCollectionTest, SessionRestoreDOne) {
TEST_F(ProfileProviderRealCollectionTest, SessionRestoreDone) {
// Restored 10 tabs.
profile_provider_->OnSessionRestoreDone(10);
profile_provider_->WaitUntilCollectionDone();
EXPECT_TRUE(profile_provider_->collection_done());
std::vector<SampledProfile> stored_profiles;
ASSERT_TRUE(profile_provider_->GetSampledProfiles(&stored_profiles));
auto& profile = stored_profiles[0];
EXPECT_EQ(SampledProfile::RESTORE_SESSION, profile.trigger_event());
ASSERT_TRUE(profile.has_perf_data());
AssertProfileData(SampledProfile::RESTORE_SESSION);
}
TEST_F(ProfileProviderRealCollectionTest, OnJankStarted) {
......@@ -211,23 +269,18 @@ TEST_F(ProfileProviderRealCollectionTest, OnJankStarted) {
profile_provider_->WaitUntilCollectionDone();
EXPECT_TRUE(profile_provider_->collection_done());
std::vector<SampledProfile> stored_profiles;
ASSERT_TRUE(profile_provider_->GetSampledProfiles(&stored_profiles));
auto& profile = stored_profiles[0];
EXPECT_EQ(SampledProfile::JANKY_TASK, profile.trigger_event());
ASSERT_TRUE(profile.has_perf_data());
AssertProfileData(SampledProfile::JANKY_TASK);
}
TEST_F(ProfileProviderRealCollectionTest, DISABLED_OnJankStopped) {
// Trigger a resume from suspend.
TEST_F(ProfileProviderRealCollectionTest, OnJankStopped) {
profile_provider_->OnJankStarted();
// Call ProfileProvider::OnJankStopped() halfway through the collection
// duration.
base::OneShotTimer stop_timer;
base::RunLoop run_loop;
stop_timer.Start(FROM_HERE, kCollectionDuration / 2,
// The jank lasts for 0.75*(collection duration), which is 1.5 sec.
stop_timer.Start(FROM_HERE, kCollectionDuration * 3 / 4,
base::BindLambdaForTesting([&]() {
profile_provider_->OnJankStopped();
run_loop.Quit();
......@@ -239,12 +292,7 @@ TEST_F(ProfileProviderRealCollectionTest, DISABLED_OnJankStopped) {
profile_provider_->WaitUntilCollectionDone();
EXPECT_TRUE(profile_provider_->collection_done());
std::vector<SampledProfile> stored_profiles;
ASSERT_TRUE(profile_provider_->GetSampledProfiles(&stored_profiles));
auto& profile = stored_profiles[0];
EXPECT_EQ(SampledProfile::JANKY_TASK, profile.trigger_event());
ASSERT_TRUE(profile.has_perf_data());
AssertProfileData(SampledProfile::JANKY_TASK);
}
} // namespace metrics
......
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