Skip to content
This repository was archived by the owner on Feb 25, 2025. It is now read-only.

Remove flake inducing timeouts #25847

Merged
dnfield merged 8 commits into from
Apr 30, 2021
Merged

Remove flake inducing timeouts #25847

Changes from 1 commit
Commits
Show all changes
8 commits
Select commit Hold shift + click to select a range
9af420d
Remove flake inducing timeouts
dnfield Apr 30, 2021
e821e4f
format
dnfield Apr 30, 2021
bdb97e3
fix mistaken wait
dnfield Apr 30, 2021
1800e04
Use wait_until
dnfield Apr 30, 2021
7b7441a
better way to check for overflow
dnfield Apr 30, 2021
26643da
doc
dnfield Apr 30, 2021
fa0f6c8
remove explicit branch
dnfield Apr 30, 2021
52e7f7f
not std::min
dnfield Apr 30, 2021
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
91 changes: 20 additions & 71 deletions shell/common/shell_unittests.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -672,7 +672,7 @@ TEST_F(ShellTest, ExternalEmbedderNoThreadMerger) {
SkPaint(SkColor4f::FromColor(SK_ColorRED)));
auto sk_picture = recorder.finishRecordingAsPicture();
fml::RefPtr<SkiaUnrefQueue> queue = fml::MakeRefCounted<SkiaUnrefQueue>(
this->GetCurrentTaskRunner(), fml::TimeDelta::FromSeconds(0));
this->GetCurrentTaskRunner(), fml::TimeDelta::Zero());
auto picture_layer = std::make_shared<PictureLayer>(
SkPoint::Make(10, 10),
flutter::SkiaGPUObject<SkPicture>({sk_picture, queue}), false, false);
Expand Down Expand Up @@ -727,7 +727,7 @@ TEST_F(ShellTest,
SkPaint(SkColor4f::FromColor(SK_ColorRED)));
auto sk_picture = recorder.finishRecordingAsPicture();
fml::RefPtr<SkiaUnrefQueue> queue = fml::MakeRefCounted<SkiaUnrefQueue>(
this->GetCurrentTaskRunner(), fml::TimeDelta::FromSeconds(0));
this->GetCurrentTaskRunner(), fml::TimeDelta::Zero());
auto picture_layer = std::make_shared<PictureLayer>(
SkPoint::Make(10, 10),
flutter::SkiaGPUObject<SkPicture>({sk_picture, queue}), false, false);
Expand Down Expand Up @@ -779,7 +779,7 @@ TEST_F(ShellTest,
SkPaint(SkColor4f::FromColor(SK_ColorRED)));
auto sk_picture = recorder.finishRecordingAsPicture();
fml::RefPtr<SkiaUnrefQueue> queue = fml::MakeRefCounted<SkiaUnrefQueue>(
this->GetCurrentTaskRunner(), fml::TimeDelta::FromSeconds(0));
this->GetCurrentTaskRunner(), fml::TimeDelta::Zero());
auto picture_layer = std::make_shared<PictureLayer>(
SkPoint::Make(10, 10),
flutter::SkiaGPUObject<SkPicture>({sk_picture, queue}), false, false);
Expand All @@ -789,8 +789,9 @@ TEST_F(ShellTest,
PumpOneFrame(shell.get(), 100, 100, builder);

auto result =
shell->WaitForFirstFrame(fml::TimeDelta::FromMilliseconds(1000));
ASSERT_TRUE(result.ok());
shell->WaitForFirstFrame(fml::TimeDelta::Max());
ASSERT_TRUE(result.ok()) << "Result: " << static_cast<int>(result.code())
<< ": " << result.message();

ASSERT_TRUE(raster_thread_merger->IsEnabled());

Expand All @@ -800,7 +801,6 @@ TEST_F(ShellTest,
// Validate the platform view can be recreated and destroyed again
ValidateShell(shell.get());
ASSERT_TRUE(raster_thread_merger->IsEnabled());

DestroyShell(std::move(shell));
}

Expand Down Expand Up @@ -853,7 +853,7 @@ TEST_F(ShellTest,
SkPaint(SkColor4f::FromColor(SK_ColorRED)));
auto sk_picture = recorder.finishRecordingAsPicture();
fml::RefPtr<SkiaUnrefQueue> queue = fml::MakeRefCounted<SkiaUnrefQueue>(
this->GetCurrentTaskRunner(), fml::TimeDelta::FromSeconds(0));
this->GetCurrentTaskRunner(), fml::TimeDelta::Zero());
auto picture_layer = std::make_shared<PictureLayer>(
SkPoint::Make(10, 10),
flutter::SkiaGPUObject<SkPicture>({sk_picture, queue}), false, false);
Expand Down Expand Up @@ -928,7 +928,7 @@ TEST_F(ShellTest,
SkPaint(SkColor4f::FromColor(SK_ColorRED)));
auto sk_picture = recorder.finishRecordingAsPicture();
fml::RefPtr<SkiaUnrefQueue> queue = fml::MakeRefCounted<SkiaUnrefQueue>(
this->GetCurrentTaskRunner(), fml::TimeDelta::FromSeconds(0));
this->GetCurrentTaskRunner(), fml::TimeDelta::Zero());
auto picture_layer = std::make_shared<PictureLayer>(
SkPoint::Make(10, 10),
flutter::SkiaGPUObject<SkPicture>({sk_picture, queue}), false, false);
Expand Down Expand Up @@ -1001,7 +1001,7 @@ TEST_F(ShellTest,
SkPaint(SkColor4f::FromColor(SK_ColorRED)));
auto sk_picture = recorder.finishRecordingAsPicture();
fml::RefPtr<SkiaUnrefQueue> queue = fml::MakeRefCounted<SkiaUnrefQueue>(
this->GetCurrentTaskRunner(), fml::TimeDelta::FromSeconds(0));
this->GetCurrentTaskRunner(), fml::TimeDelta::Zero());
auto picture_layer = std::make_shared<PictureLayer>(
SkPoint::Make(10, 10),
flutter::SkiaGPUObject<SkPicture>({sk_picture, queue}), false, false);
Expand Down Expand Up @@ -1049,7 +1049,7 @@ TEST_F(ShellTest, OnPlatformViewDestroyWithoutRasterThreadMerger) {
SkPaint(SkColor4f::FromColor(SK_ColorRED)));
auto sk_picture = recorder.finishRecordingAsPicture();
fml::RefPtr<SkiaUnrefQueue> queue = fml::MakeRefCounted<SkiaUnrefQueue>(
this->GetCurrentTaskRunner(), fml::TimeDelta::FromSeconds(0));
this->GetCurrentTaskRunner(), fml::TimeDelta::Zero());
auto picture_layer = std::make_shared<PictureLayer>(
SkPoint::Make(10, 10),
flutter::SkiaGPUObject<SkPicture>({sk_picture, queue}), false, false);
Expand Down Expand Up @@ -1120,7 +1120,7 @@ TEST_F(ShellTest,
SkPaint(SkColor4f::FromColor(SK_ColorRED)));
auto sk_picture = recorder.finishRecordingAsPicture();
fml::RefPtr<SkiaUnrefQueue> queue = fml::MakeRefCounted<SkiaUnrefQueue>(
this->GetCurrentTaskRunner(), fml::TimeDelta::FromSeconds(0));
this->GetCurrentTaskRunner(), fml::TimeDelta::Zero());
auto picture_layer = std::make_shared<PictureLayer>(
SkPoint::Make(10, 10),
flutter::SkiaGPUObject<SkPicture>({sk_picture, queue}), false, false);
Expand Down Expand Up @@ -1263,57 +1263,6 @@ TEST(SettingsTest, FrameTimingSetsAndGetsProperly) {
}
}

#if FLUTTER_RELEASE
TEST_F(ShellTest, ReportTimingsIsCalledLaterInReleaseMode) {
#else
TEST_F(ShellTest, ReportTimingsIsCalledSoonerInNonReleaseMode) {
#endif
fml::TimePoint start = fml::TimePoint::Now();
auto settings = CreateSettingsForFixture();
std::unique_ptr<Shell> shell = CreateShell(settings);

// Create the surface needed by rasterizer
PlatformViewNotifyCreated(shell.get());

auto configuration = RunConfiguration::InferFromSettings(settings);
ASSERT_TRUE(configuration.IsValid());
configuration.SetEntrypoint("reportTimingsMain");

// Wait for 2 reports: the first one is the immediate callback of the first
// frame; the second one will exercise the batching logic.
fml::CountDownLatch reportLatch(2);
std::vector<int64_t> timestamps;
auto nativeTimingCallback = [&reportLatch,
&timestamps](Dart_NativeArguments args) {
Dart_Handle exception = nullptr;
timestamps = tonic::DartConverter<std::vector<int64_t>>::FromArguments(
args, 0, exception);
reportLatch.CountDown();
};
AddNativeCallback("NativeReportTimingsCallback",
CREATE_NATIVE_ENTRY(nativeTimingCallback));
RunEngine(shell.get(), std::move(configuration));

PumpOneFrame(shell.get());
PumpOneFrame(shell.get());

reportLatch.Wait();
DestroyShell(std::move(shell));

fml::TimePoint finish = fml::TimePoint::Now();
fml::TimeDelta elapsed = finish - start;

#if FLUTTER_RELEASE
// Our batch time is 1000ms. Hopefully the 800ms limit is relaxed enough to
// make it not too flaky.
ASSERT_TRUE(elapsed >= fml::TimeDelta::FromMilliseconds(800));
#else
// Our batch time is 100ms. Hopefully the 500ms limit is relaxed enough to
// make it not too flaky.
ASSERT_TRUE(elapsed <= fml::TimeDelta::FromMilliseconds(500));
#endif
Comment on lines -1306 to -1314

@gaaclarke gaaclarke Apr 30, 2021

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Seems like you could get what you want by just removing this assert right? That would eliminate all timeout except the one that's for the whole test.

@gaaclarke gaaclarke Apr 30, 2021

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm just realizing that's the whole point of this test. It doesn't really test much without it =T

@gaaclarke gaaclarke Apr 30, 2021

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Deleting this LGTM, I'd double check with the author of it just to see if they can think of another way to assert what they want.

@dnfield dnfield Apr 30, 2021

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Author is @liyuqian

@dnfield dnfield Apr 30, 2021

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah the more I think about this, this either needs to be a benchmark and run as one, or it needs to mock out the clock to assert how many ticks can pass before events are emitted.

}

TEST_F(ShellTest, ReportTimingsIsCalledImmediatelyAfterTheFirstFrame) {
auto settings = CreateSettingsForFixture();
std::unique_ptr<Shell> shell = CreateShell(settings);
Expand Down Expand Up @@ -1392,7 +1341,7 @@ TEST_F(ShellTest, WaitForFirstFrame) {
RunEngine(shell.get(), std::move(configuration));
PumpOneFrame(shell.get());
fml::Status result =
shell->WaitForFirstFrame(fml::TimeDelta::FromMilliseconds(1000));
shell->WaitForFirstFrame(fml::TimeDelta::Max());
ASSERT_TRUE(result.ok());

DestroyShell(std::move(shell));
Expand All @@ -1411,7 +1360,7 @@ TEST_F(ShellTest, WaitForFirstFrameZeroSizeFrame) {
RunEngine(shell.get(), std::move(configuration));
PumpOneFrame(shell.get(), {1.0, 0.0, 0.0});
fml::Status result =
shell->WaitForFirstFrame(fml::TimeDelta::FromMilliseconds(1000));
shell->WaitForFirstFrame(fml::TimeDelta::Max());
ASSERT_FALSE(result.ok());
ASSERT_EQ(result.code(), fml::StatusCode::kDeadlineExceeded);

Expand All @@ -1430,7 +1379,7 @@ TEST_F(ShellTest, WaitForFirstFrameTimeout) {

RunEngine(shell.get(), std::move(configuration));
fml::Status result =
shell->WaitForFirstFrame(fml::TimeDelta::FromMilliseconds(10));
shell->WaitForFirstFrame(fml::TimeDelta::Zero());

@blasten blasten Apr 30, 2021

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

is the assert below right? It seems to be expecting a timeout indeed.

@dnfield dnfield Apr 30, 2021

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes. We're saying we want to wait zero ms now instead of waiting 10. Theoretically something could actually produce a frame in 10ms. Even this isn't bullet proof but it's better.

@blasten blasten Apr 30, 2021

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

are we sure that the intention is to time out as soon as possible, or to wait enough time? I wonder why 10 was chosen.

@dnfield dnfield Apr 30, 2021

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It's very likely because that was short enough on the developer's machine to trigger the timeout. The problem is, on a fast enough machine or with enough improvements to the code under test, 10ms might not be long enough.

@dnfield dnfield Apr 30, 2021

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

IOW, this test is currently trying to wait 10ms of monotonic time and seeing if it can or can't do work in that time. But that's susceptible to flakes.

ASSERT_FALSE(result.ok());
ASSERT_EQ(result.code(), fml::StatusCode::kDeadlineExceeded);

Expand All @@ -1450,10 +1399,10 @@ TEST_F(ShellTest, WaitForFirstFrameMultiple) {
RunEngine(shell.get(), std::move(configuration));
PumpOneFrame(shell.get());
fml::Status result =
shell->WaitForFirstFrame(fml::TimeDelta::FromMilliseconds(1000));
shell->WaitForFirstFrame(fml::TimeDelta::Max());
ASSERT_TRUE(result.ok());
for (int i = 0; i < 100; ++i) {
result = shell->WaitForFirstFrame(fml::TimeDelta::FromMilliseconds(1));
result = shell->WaitForFirstFrame(fml::TimeDelta::Zero());
ASSERT_TRUE(result.ok());
}

Expand Down Expand Up @@ -1481,12 +1430,12 @@ TEST_F(ShellTest, WaitForFirstFrameInlined) {
fml::AutoResetWaitableEvent event;
task_runner->PostTask([&shell, &event] {
fml::Status result =
shell->WaitForFirstFrame(fml::TimeDelta::FromMilliseconds(1000));
shell->WaitForFirstFrame(fml::TimeDelta::Max());
ASSERT_FALSE(result.ok());
ASSERT_EQ(result.code(), fml::StatusCode::kFailedPrecondition);
event.Signal();
});
ASSERT_FALSE(event.WaitWithTimeout(fml::TimeDelta::FromMilliseconds(1000)));
ASSERT_FALSE(event.WaitWithTimeout(fml::TimeDelta::Max()));

DestroyShell(std::move(shell), std::move(task_runners));
}
Expand Down Expand Up @@ -1815,7 +1764,7 @@ TEST_F(ShellTest, Screenshot) {
SkPaint(SkColor4f::FromColor(SK_ColorRED)));
auto sk_picture = recorder.finishRecordingAsPicture();
fml::RefPtr<SkiaUnrefQueue> queue = fml::MakeRefCounted<SkiaUnrefQueue>(
this->GetCurrentTaskRunner(), fml::TimeDelta::FromSeconds(0));
this->GetCurrentTaskRunner(), fml::TimeDelta::Zero());
auto picture_layer = std::make_shared<PictureLayer>(
SkPoint::Make(10, 10),
flutter::SkiaGPUObject<SkPicture>({sk_picture, queue}), false, false);
Expand Down Expand Up @@ -2105,7 +2054,7 @@ TEST_F(ShellTest, OnServiceProtocolEstimateRasterCacheMemoryWorks) {
// 1. Construct a picture and a picture layer to be raster cached.
sk_sp<SkPicture> picture = MakeSizedPicture(10, 10);
fml::RefPtr<SkiaUnrefQueue> queue = fml::MakeRefCounted<SkiaUnrefQueue>(
GetCurrentTaskRunner(), fml::TimeDelta::FromSeconds(0));
GetCurrentTaskRunner(), fml::TimeDelta::Zero());
auto picture_layer = std::make_shared<PictureLayer>(
SkPoint::Make(0, 0),
flutter::SkiaGPUObject<SkPicture>({MakeSizedPicture(100, 100), queue}),
Expand Down