Commit 3dc4646c authored by Brian Sheedy's avatar Brian Sheedy Committed by Commit Bot

Switch net_perftests to histograms

Switches use of PrintResult in net_perftests to PerfResultReporter and
whitelists net_perftests for conversion to histograms before uploading
to the perf dashboard.

The majority of tests in net_perftests didn't actually use PrintResult,
instead just logging to stdout in a format not usable by the parsing
script. These have all been changed to use PerfResultReporter as well
so that results from these tests actually show up on the perf dashboard.

Bug: 923564
Change-Id: I172cd364bdc00a8f59666d8c822c0a3c6482fb8e
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1809116Reviewed-by: default avatarMatt Menke <mmenke@chromium.org>
Reviewed-by: default avatarRyan Hamilton <rch@chromium.org>
Commit-Queue: Brian Sheedy <bsheedy@chromium.org>
Cr-Commit-Position: refs/heads/master@{#699443}
parent 29406103
...@@ -10,6 +10,7 @@ ...@@ -10,6 +10,7 @@
#include "base/logging.h" #include "base/logging.h"
#include "base/timer/elapsed_timer.h" #include "base/timer/elapsed_timer.h"
#include "testing/gtest/include/gtest/gtest.h" #include "testing/gtest/include/gtest/gtest.h"
#include "testing/perf/perf_result_reporter.h"
namespace net { namespace net {
namespace { namespace {
...@@ -94,9 +95,12 @@ TEST(MimeSnifferTest, PlainTextPerfTest) { ...@@ -94,9 +95,12 @@ TEST(MimeSnifferTest, PlainTextPerfTest) {
RunLooksLikeBinary(plaintext, kWarmupIterations); RunLooksLikeBinary(plaintext, kWarmupIterations);
base::ElapsedTimer elapsed_timer; base::ElapsedTimer elapsed_timer;
RunLooksLikeBinary(plaintext, kMeasuredIterations); RunLooksLikeBinary(plaintext, kMeasuredIterations);
LOG(INFO) << (elapsed_timer.Elapsed().InMicroseconds() * 1000 * 1024 / perf_test::PerfResultReporter reporter("MimeSniffer.", "PlainText");
(static_cast<int64_t>(plaintext.size()) * kMeasuredIterations)) reporter.RegisterImportantMetric("throughput",
<< "ns per KB"; "bytesPerSecond_biggerIsBetter");
reporter.AddResult("throughput", static_cast<int64_t>(plaintext.size()) *
kMeasuredIterations /
elapsed_timer.Elapsed().InSecondsF());
} }
} // namespace } // namespace
......
...@@ -11,15 +11,16 @@ ...@@ -11,15 +11,16 @@
#include "base/run_loop.h" #include "base/run_loop.h"
#include "base/strings/string_util.h" #include "base/strings/string_util.h"
#include "base/strings/stringprintf.h" #include "base/strings/stringprintf.h"
#include "base/test/perf_time_logger.h"
#include "base/test/task_environment.h" #include "base/test/task_environment.h"
#include "base/time/time.h" #include "base/time/time.h"
#include "base/timer/elapsed_timer.h"
#include "net/cookies/canonical_cookie.h" #include "net/cookies/canonical_cookie.h"
#include "net/cookies/cookie_monster.h" #include "net/cookies/cookie_monster.h"
#include "net/cookies/cookie_monster_store_test.h" #include "net/cookies/cookie_monster_store_test.h"
#include "net/cookies/cookie_util.h" #include "net/cookies/cookie_util.h"
#include "net/cookies/parsed_cookie.h" #include "net/cookies/parsed_cookie.h"
#include "testing/gtest/include/gtest/gtest.h" #include "testing/gtest/include/gtest/gtest.h"
#include "testing/perf/perf_result_reporter.h"
#include "url/gurl.h" #include "url/gurl.h"
namespace net { namespace net {
...@@ -30,6 +31,36 @@ const int kNumCookies = 20000; ...@@ -30,6 +31,36 @@ const int kNumCookies = 20000;
const char kCookieLine[] = "A = \"b=;\\\"\" ;secure;;;"; const char kCookieLine[] = "A = \"b=;\\\"\" ;secure;;;";
const char kGoogleURL[] = "http://www.foo.com"; const char kGoogleURL[] = "http://www.foo.com";
static constexpr char kMetricPrefixParsedCookie[] = "ParsedCookie.";
static constexpr char kMetricPrefixCookieMonster[] = "CookieMonster.";
static constexpr char kMetricParseTimeMs[] = "parse_time";
static constexpr char kMetricAddTimeMs[] = "add_time";
static constexpr char kMetricQueryTimeMs[] = "query_time";
static constexpr char kMetricDeleteAllTimeMs[] = "delete_all_time";
static constexpr char kMetricQueryDomainTimeMs[] = "query_domain_time";
static constexpr char kMetricImportTimeMs[] = "import_time";
static constexpr char kMetricGetKeyTimeMs[] = "get_key_time";
static constexpr char kMetricGCTimeMs[] = "gc_time";
perf_test::PerfResultReporter SetUpParseReporter(const std::string& story) {
perf_test::PerfResultReporter reporter(kMetricPrefixParsedCookie, story);
reporter.RegisterImportantMetric(kMetricParseTimeMs, "ms");
return reporter;
}
perf_test::PerfResultReporter SetUpCookieMonsterReporter(
const std::string& story) {
perf_test::PerfResultReporter reporter(kMetricPrefixCookieMonster, story);
reporter.RegisterImportantMetric(kMetricAddTimeMs, "ms");
reporter.RegisterImportantMetric(kMetricQueryTimeMs, "ms");
reporter.RegisterImportantMetric(kMetricDeleteAllTimeMs, "ms");
reporter.RegisterImportantMetric(kMetricQueryDomainTimeMs, "ms");
reporter.RegisterImportantMetric(kMetricImportTimeMs, "ms");
reporter.RegisterImportantMetric(kMetricGetKeyTimeMs, "ms");
reporter.RegisterImportantMetric(kMetricGCTimeMs, "ms");
return reporter;
}
class CookieMonsterTest : public testing::Test { class CookieMonsterTest : public testing::Test {
public: public:
CookieMonsterTest() {} CookieMonsterTest() {}
...@@ -122,23 +153,25 @@ class GetAllCookiesCallback : public CookieTestCallback { ...@@ -122,23 +153,25 @@ class GetAllCookiesCallback : public CookieTestCallback {
TEST(ParsedCookieTest, TestParseCookies) { TEST(ParsedCookieTest, TestParseCookies) {
std::string cookie(kCookieLine); std::string cookie(kCookieLine);
base::PerfTimeLogger timer("Parsed_cookie_parse_cookies"); auto reporter = SetUpParseReporter("parse_cookies");
base::ElapsedTimer timer;
for (int i = 0; i < kNumCookies; ++i) { for (int i = 0; i < kNumCookies; ++i) {
ParsedCookie pc(cookie); ParsedCookie pc(cookie);
EXPECT_TRUE(pc.IsValid()); EXPECT_TRUE(pc.IsValid());
} }
timer.Done(); reporter.AddResult(kMetricParseTimeMs, timer.Elapsed().InMillisecondsF());
} }
TEST(ParsedCookieTest, TestParseBigCookies) { TEST(ParsedCookieTest, TestParseBigCookies) {
std::string cookie(3800, 'z'); std::string cookie(3800, 'z');
cookie += kCookieLine; cookie += kCookieLine;
base::PerfTimeLogger timer("Parsed_cookie_parse_big_cookies"); auto reporter = SetUpParseReporter("parse_big_cookies");
base::ElapsedTimer timer;
for (int i = 0; i < kNumCookies; ++i) { for (int i = 0; i < kNumCookies; ++i) {
ParsedCookie pc(cookie); ParsedCookie pc(cookie);
EXPECT_TRUE(pc.IsValid()); EXPECT_TRUE(pc.IsValid());
} }
timer.Done(); reporter.AddResult(kMetricParseTimeMs, timer.Elapsed().InMillisecondsF());
} }
TEST_F(CookieMonsterTest, TestAddCookiesOnSingleHost) { TEST_F(CookieMonsterTest, TestAddCookiesOnSingleHost) {
...@@ -151,27 +184,30 @@ TEST_F(CookieMonsterTest, TestAddCookiesOnSingleHost) { ...@@ -151,27 +184,30 @@ TEST_F(CookieMonsterTest, TestAddCookiesOnSingleHost) {
SetCookieCallback setCookieCallback; SetCookieCallback setCookieCallback;
// Add a bunch of cookies on a single host // Add a bunch of cookies on a single host
base::PerfTimeLogger timer("Cookie_monster_add_single_host"); auto reporter = SetUpCookieMonsterReporter("single_host");
base::ElapsedTimer add_timer;
for (std::vector<std::string>::const_iterator it = cookies.begin(); for (std::vector<std::string>::const_iterator it = cookies.begin();
it != cookies.end(); ++it) { it != cookies.end(); ++it) {
setCookieCallback.SetCookie(cm.get(), GURL(kGoogleURL), *it); setCookieCallback.SetCookie(cm.get(), GURL(kGoogleURL), *it);
} }
timer.Done(); reporter.AddResult(kMetricAddTimeMs, add_timer.Elapsed().InMillisecondsF());
GetCookieListCallback getCookieListCallback; GetCookieListCallback getCookieListCallback;
base::PerfTimeLogger timer2("Cookie_monster_query_single_host"); base::ElapsedTimer query_timer;
for (std::vector<std::string>::const_iterator it = cookies.begin(); for (std::vector<std::string>::const_iterator it = cookies.begin();
it != cookies.end(); ++it) { it != cookies.end(); ++it) {
getCookieListCallback.GetCookieList(cm.get(), GURL(kGoogleURL)); getCookieListCallback.GetCookieList(cm.get(), GURL(kGoogleURL));
} }
timer2.Done(); reporter.AddResult(kMetricQueryTimeMs,
query_timer.Elapsed().InMillisecondsF());
base::PerfTimeLogger timer3("Cookie_monster_deleteall_single_host"); base::ElapsedTimer delete_all_timer;
cm->DeleteAllAsync(CookieMonster::DeleteCallback()); cm->DeleteAllAsync(CookieMonster::DeleteCallback());
base::RunLoop().RunUntilIdle(); base::RunLoop().RunUntilIdle();
timer3.Done(); reporter.AddResult(kMetricDeleteAllTimeMs,
delete_all_timer.Elapsed().InMillisecondsF());
} }
TEST_F(CookieMonsterTest, TestAddCookieOnManyHosts) { TEST_F(CookieMonsterTest, TestAddCookieOnManyHosts) {
...@@ -185,26 +221,29 @@ TEST_F(CookieMonsterTest, TestAddCookieOnManyHosts) { ...@@ -185,26 +221,29 @@ TEST_F(CookieMonsterTest, TestAddCookieOnManyHosts) {
SetCookieCallback setCookieCallback; SetCookieCallback setCookieCallback;
// Add a cookie on a bunch of host // Add a cookie on a bunch of host
base::PerfTimeLogger timer("Cookie_monster_add_many_hosts"); auto reporter = SetUpCookieMonsterReporter("many_hosts");
base::ElapsedTimer add_timer;
for (std::vector<GURL>::const_iterator it = gurls.begin(); it != gurls.end(); for (std::vector<GURL>::const_iterator it = gurls.begin(); it != gurls.end();
++it) { ++it) {
setCookieCallback.SetCookie(cm.get(), *it, cookie); setCookieCallback.SetCookie(cm.get(), *it, cookie);
} }
timer.Done(); reporter.AddResult(kMetricAddTimeMs, add_timer.Elapsed().InMillisecondsF());
GetCookieListCallback getCookieListCallback; GetCookieListCallback getCookieListCallback;
base::PerfTimeLogger timer2("Cookie_monster_query_many_hosts"); base::ElapsedTimer query_timer;
for (std::vector<GURL>::const_iterator it = gurls.begin(); it != gurls.end(); for (std::vector<GURL>::const_iterator it = gurls.begin(); it != gurls.end();
++it) { ++it) {
getCookieListCallback.GetCookieList(cm.get(), *it); getCookieListCallback.GetCookieList(cm.get(), *it);
} }
timer2.Done(); reporter.AddResult(kMetricQueryTimeMs,
query_timer.Elapsed().InMillisecondsF());
base::PerfTimeLogger timer3("Cookie_monster_deleteall_many_hosts"); base::ElapsedTimer delete_all_timer;
cm->DeleteAllAsync(CookieMonster::DeleteCallback()); cm->DeleteAllAsync(CookieMonster::DeleteCallback());
base::RunLoop().RunUntilIdle(); base::RunLoop().RunUntilIdle();
timer3.Done(); reporter.AddResult(kMetricDeleteAllTimeMs,
delete_all_timer.Elapsed().InMillisecondsF());
} }
TEST_F(CookieMonsterTest, TestDomainTree) { TEST_F(CookieMonsterTest, TestDomainTree) {
...@@ -256,11 +295,13 @@ TEST_F(CookieMonsterTest, TestDomainTree) { ...@@ -256,11 +295,13 @@ TEST_F(CookieMonsterTest, TestDomainTree) {
getCookieListCallback.GetCookieList(cm.get(), probe_gurl); getCookieListCallback.GetCookieList(cm.get(), probe_gurl);
EXPECT_EQ(5u, cookie_list.size()) EXPECT_EQ(5u, cookie_list.size())
<< CanonicalCookie::BuildCookieLine(cookie_list); << CanonicalCookie::BuildCookieLine(cookie_list);
base::PerfTimeLogger timer("Cookie_monster_query_domain_tree"); auto reporter = SetUpCookieMonsterReporter("tree");
base::ElapsedTimer query_domain_timer;
for (int i = 0; i < kNumCookies; i++) { for (int i = 0; i < kNumCookies; i++) {
getCookieListCallback.GetCookieList(cm.get(), probe_gurl); getCookieListCallback.GetCookieList(cm.get(), probe_gurl);
} }
timer.Done(); reporter.AddResult(kMetricQueryDomainTimeMs,
query_domain_timer.Elapsed().InMillisecondsF());
} }
TEST_F(CookieMonsterTest, TestDomainLine) { TEST_F(CookieMonsterTest, TestDomainLine) {
...@@ -296,11 +337,13 @@ TEST_F(CookieMonsterTest, TestDomainLine) { ...@@ -296,11 +337,13 @@ TEST_F(CookieMonsterTest, TestDomainLine) {
const CookieList& cookie_list = const CookieList& cookie_list =
getCookieListCallback.GetCookieList(cm.get(), probe_gurl); getCookieListCallback.GetCookieList(cm.get(), probe_gurl);
EXPECT_EQ(32u, cookie_list.size()); EXPECT_EQ(32u, cookie_list.size());
base::PerfTimeLogger timer2("Cookie_monster_query_domain_line"); auto reporter = SetUpCookieMonsterReporter("line");
base::ElapsedTimer query_domain_timer;
for (int i = 0; i < kNumCookies; i++) { for (int i = 0; i < kNumCookies; i++) {
getCookieListCallback.GetCookieList(cm.get(), probe_gurl); getCookieListCallback.GetCookieList(cm.get(), probe_gurl);
} }
timer2.Done(); reporter.AddResult(kMetricQueryDomainTimeMs,
query_domain_timer.Elapsed().InMillisecondsF());
} }
TEST_F(CookieMonsterTest, TestImport) { TEST_F(CookieMonsterTest, TestImport) {
...@@ -330,9 +373,11 @@ TEST_F(CookieMonsterTest, TestImport) { ...@@ -330,9 +373,11 @@ TEST_F(CookieMonsterTest, TestImport) {
// Import will happen on first access. // Import will happen on first access.
GURL gurl("www.foo.com"); GURL gurl("www.foo.com");
CookieOptions options; CookieOptions options;
base::PerfTimeLogger timer("Cookie_monster_import_from_store"); auto reporter = SetUpCookieMonsterReporter("from_store");
base::ElapsedTimer import_timer;
getCookieListCallback.GetCookieList(cm.get(), gurl); getCookieListCallback.GetCookieList(cm.get(), gurl);
timer.Done(); reporter.AddResult(kMetricImportTimeMs,
import_timer.Elapsed().InMillisecondsF());
// Just confirm keys were set as expected. // Just confirm keys were set as expected.
EXPECT_EQ("domain_1.com", cm->GetKey("www.Domain_1.com")); EXPECT_EQ("domain_1.com", cm->GetKey("www.Domain_1.com"));
...@@ -340,10 +385,12 @@ TEST_F(CookieMonsterTest, TestImport) { ...@@ -340,10 +385,12 @@ TEST_F(CookieMonsterTest, TestImport) {
TEST_F(CookieMonsterTest, TestGetKey) { TEST_F(CookieMonsterTest, TestGetKey) {
std::unique_ptr<CookieMonster> cm(new CookieMonster(nullptr, nullptr)); std::unique_ptr<CookieMonster> cm(new CookieMonster(nullptr, nullptr));
base::PerfTimeLogger timer("Cookie_monster_get_key"); auto reporter = SetUpCookieMonsterReporter("baseline_story");
base::ElapsedTimer get_key_timer;
for (int i = 0; i < kNumCookies; i++) for (int i = 0; i < kNumCookies; i++)
cm->GetKey("www.foo.com"); cm->GetKey("www.foo.com");
timer.Done(); reporter.AddResult(kMetricGetKeyTimeMs,
get_key_timer.Elapsed().InMillisecondsF());
} }
// This test is probing for whether garbage collection happens when it // This test is probing for whether garbage collection happens when it
...@@ -403,10 +450,11 @@ TEST_F(CookieMonsterTest, TestGCTimes) { ...@@ -403,10 +450,11 @@ TEST_F(CookieMonsterTest, TestGCTimes) {
// Trigger the Garbage collection we're allowed. // Trigger the Garbage collection we're allowed.
setCookieCallback.SetCookie(cm.get(), gurl, cookie_line); setCookieCallback.SetCookie(cm.get(), gurl, cookie_line);
base::PerfTimeLogger timer((std::string("GC_") + test_case.name).c_str()); auto reporter = SetUpCookieMonsterReporter(test_case.name);
base::ElapsedTimer gc_timer;
for (int i = 0; i < kNumCookies; i++) for (int i = 0; i < kNumCookies; i++)
setCookieCallback.SetCookie(cm.get(), gurl, cookie_line); setCookieCallback.SetCookie(cm.get(), gurl, cookie_line);
timer.Done(); reporter.AddResult(kMetricGCTimeMs, gc_timer.Elapsed().InMillisecondsF());
} }
} }
......
This diff is collapsed.
...@@ -14,15 +14,15 @@ ...@@ -14,15 +14,15 @@
#include "base/strings/stringprintf.h" #include "base/strings/stringprintf.h"
#include "base/synchronization/waitable_event.h" #include "base/synchronization/waitable_event.h"
#include "base/task/post_task.h" #include "base/task/post_task.h"
#include "base/test/perf_time_logger.h"
#include "base/test/task_environment.h" #include "base/test/task_environment.h"
#include "base/timer/elapsed_timer.h"
#include "net/base/test_completion_callback.h" #include "net/base/test_completion_callback.h"
#include "net/cookies/canonical_cookie.h" #include "net/cookies/canonical_cookie.h"
#include "net/cookies/cookie_constants.h" #include "net/cookies/cookie_constants.h"
#include "net/extras/sqlite/cookie_crypto_delegate.h" #include "net/extras/sqlite/cookie_crypto_delegate.h"
#include "net/log/net_log_with_source.h" #include "net/log/net_log_with_source.h"
#include "testing/gtest/include/gtest/gtest.h" #include "testing/gtest/include/gtest/gtest.h"
#include "testing/perf/perf_test.h" #include "testing/perf/perf_result_reporter.h"
#include "url/gurl.h" #include "url/gurl.h"
namespace net { namespace net {
...@@ -43,6 +43,15 @@ static_assert(kRandomSeed > 10 * kNumDomains, ...@@ -43,6 +43,15 @@ static_assert(kRandomSeed > 10 * kNumDomains,
static_assert(kRandomSeed > 10 * kCookiesPerDomain, static_assert(kRandomSeed > 10 * kCookiesPerDomain,
"kRandomSeed not high enough for number of cookies per domain"); "kRandomSeed not high enough for number of cookies per domain");
static constexpr char kMetricPrefixSQLPCS[] = "SQLitePersistentCookieStore.";
static constexpr char kMetricOperationDurationMs[] = "operation_duration";
perf_test::PerfResultReporter SetUpSQLPCSReporter(const std::string& story) {
perf_test::PerfResultReporter reporter(kMetricPrefixSQLPCS, story);
reporter.RegisterImportantMetric(kMetricOperationDurationMs, "ms");
return reporter;
}
} // namespace } // namespace
class SQLitePersistentCookieStorePerfTest : public testing::Test { class SQLitePersistentCookieStorePerfTest : public testing::Test {
...@@ -127,15 +136,12 @@ class SQLitePersistentCookieStorePerfTest : public testing::Test { ...@@ -127,15 +136,12 @@ class SQLitePersistentCookieStorePerfTest : public testing::Test {
perf_measurement_start_ = base::Time::Now(); perf_measurement_start_ = base::Time::Now();
} }
void EndPerfMeasurement() { void EndPerfMeasurement(const std::string& story) {
DCHECK(!perf_measurement_start_.is_null()); DCHECK(!perf_measurement_start_.is_null());
base::TimeDelta elapsed = base::Time::Now() - perf_measurement_start_; base::TimeDelta elapsed = base::Time::Now() - perf_measurement_start_;
perf_measurement_start_ = base::Time(); perf_measurement_start_ = base::Time();
const ::testing::TestInfo* test_info = auto reporter = SetUpSQLPCSReporter(story);
::testing::UnitTest::GetInstance()->current_test_info(); reporter.AddResult(kMetricOperationDurationMs, elapsed.InMillisecondsF());
perf_test::PrintResult(
test_info->test_case_name(), std::string(".") + test_info->name(),
"time", static_cast<double>(elapsed.InMilliseconds()), "ms", true);
} }
protected: protected:
...@@ -165,7 +171,7 @@ TEST_F(SQLitePersistentCookieStorePerfTest, TestLoadForKeyPerformance) { ...@@ -165,7 +171,7 @@ TEST_F(SQLitePersistentCookieStorePerfTest, TestLoadForKeyPerformance) {
base::BindOnce(&SQLitePersistentCookieStorePerfTest::OnKeyLoaded, base::BindOnce(&SQLitePersistentCookieStorePerfTest::OnKeyLoaded,
base::Unretained(this))); base::Unretained(this)));
key_loaded_event_.Wait(); key_loaded_event_.Wait();
EndPerfMeasurement(); EndPerfMeasurement("load_for_key");
ASSERT_EQ(50U, cookies_.size()); ASSERT_EQ(50U, cookies_.size());
} }
...@@ -175,7 +181,7 @@ TEST_F(SQLitePersistentCookieStorePerfTest, TestLoadForKeyPerformance) { ...@@ -175,7 +181,7 @@ TEST_F(SQLitePersistentCookieStorePerfTest, TestLoadForKeyPerformance) {
TEST_F(SQLitePersistentCookieStorePerfTest, TestLoadPerformance) { TEST_F(SQLitePersistentCookieStorePerfTest, TestLoadPerformance) {
StartPerfMeasurement(); StartPerfMeasurement();
Load(); Load();
EndPerfMeasurement(); EndPerfMeasurement("load");
ASSERT_EQ(kNumDomains * kCookiesPerDomain, static_cast<int>(cookies_.size())); ASSERT_EQ(kNumDomains * kCookiesPerDomain, static_cast<int>(cookies_.size()));
} }
...@@ -214,7 +220,7 @@ TEST_F(SQLitePersistentCookieStorePerfTest, TestDeletePerformance) { ...@@ -214,7 +220,7 @@ TEST_F(SQLitePersistentCookieStorePerfTest, TestDeletePerformance) {
store_->Flush(test_closure.closure()); store_->Flush(test_closure.closure());
test_closure.WaitForResult(); test_closure.WaitForResult();
} }
EndPerfMeasurement(); EndPerfMeasurement("delete");
} }
// Test update performance. // Test update performance.
...@@ -241,7 +247,7 @@ TEST_F(SQLitePersistentCookieStorePerfTest, TestUpdatePerformance) { ...@@ -241,7 +247,7 @@ TEST_F(SQLitePersistentCookieStorePerfTest, TestUpdatePerformance) {
store_->Flush(test_closure.closure()); store_->Flush(test_closure.closure());
test_closure.WaitForResult(); test_closure.WaitForResult();
} }
EndPerfMeasurement(); EndPerfMeasurement("update");
} }
} // namespace net } // namespace net
...@@ -5,8 +5,8 @@ ...@@ -5,8 +5,8 @@
#include "base/bind.h" #include "base/bind.h"
#include "base/memory/weak_ptr.h" #include "base/memory/weak_ptr.h"
#include "base/run_loop.h" #include "base/run_loop.h"
#include "base/test/perf_time_logger.h"
#include "base/test/task_environment.h" #include "base/test/task_environment.h"
#include "base/timer/elapsed_timer.h"
#include "net/base/io_buffer.h" #include "net/base/io_buffer.h"
#include "net/base/ip_endpoint.h" #include "net/base/ip_endpoint.h"
#include "net/base/net_errors.h" #include "net/base/net_errors.h"
...@@ -19,6 +19,7 @@ ...@@ -19,6 +19,7 @@
#include "net/traffic_annotation/network_traffic_annotation_test_helper.h" #include "net/traffic_annotation/network_traffic_annotation_test_helper.h"
#include "testing/gmock/include/gmock/gmock.h" #include "testing/gmock/include/gmock/gmock.h"
#include "testing/gtest/include/gtest/gtest.h" #include "testing/gtest/include/gtest/gtest.h"
#include "testing/perf/perf_result_reporter.h"
#include "testing/platform_test.h" #include "testing/platform_test.h"
using net::test::IsOk; using net::test::IsOk;
...@@ -27,6 +28,18 @@ namespace net { ...@@ -27,6 +28,18 @@ namespace net {
namespace { namespace {
static constexpr char kMetricPrefixUDPSocket[] = "UDPSocketWrite.";
static constexpr char kMetricElapsedTimeMs[] = "elapsed_time";
static constexpr char kMetricWriteSpeedBytesPerSecond[] = "write_speed";
perf_test::PerfResultReporter SetUpUDPSocketReporter(const std::string& story) {
perf_test::PerfResultReporter reporter(kMetricPrefixUDPSocket, story);
reporter.RegisterImportantMetric(kMetricElapsedTimeMs, "ms");
reporter.RegisterImportantMetric(kMetricWriteSpeedBytesPerSecond,
"bytesPerSecond_biggerIsBetter");
return reporter;
}
class UDPSocketPerfTest : public PlatformTest { class UDPSocketPerfTest : public PlatformTest {
public: public:
UDPSocketPerfTest() UDPSocketPerfTest()
...@@ -91,6 +104,7 @@ void UDPSocketPerfTest::WritePacketsToSocket(UDPClientSocket* socket, ...@@ -91,6 +104,7 @@ void UDPSocketPerfTest::WritePacketsToSocket(UDPClientSocket* socket,
} }
void UDPSocketPerfTest::WriteBenchmark(bool use_nonblocking_io) { void UDPSocketPerfTest::WriteBenchmark(bool use_nonblocking_io) {
base::ElapsedTimer total_elapsed_timer;
base::test::SingleThreadTaskEnvironment task_environment( base::test::SingleThreadTaskEnvironment task_environment(
base::test::SingleThreadTaskEnvironment::MainThreadType::IO); base::test::SingleThreadTaskEnvironment::MainThreadType::IO);
const uint16_t kPort = 9999; const uint16_t kPort = 9999;
...@@ -116,23 +130,26 @@ void UDPSocketPerfTest::WriteBenchmark(bool use_nonblocking_io) { ...@@ -116,23 +130,26 @@ void UDPSocketPerfTest::WriteBenchmark(bool use_nonblocking_io) {
EXPECT_THAT(rv, IsOk()); EXPECT_THAT(rv, IsOk());
base::RunLoop run_loop; base::RunLoop run_loop;
base::TimeTicks start_ticks = base::TimeTicks::Now(); base::ElapsedTimer write_elapsed_timer;
int packets = 100000; int packets = 100000;
client->SetSendBufferSize(1024); client->SetSendBufferSize(1024);
WritePacketsToSocket(client.get(), packets, run_loop.QuitClosure()); WritePacketsToSocket(client.get(), packets, run_loop.QuitClosure());
run_loop.Run(); run_loop.Run();
double elapsed = (base::TimeTicks::Now() - start_ticks).InSecondsF(); double write_elapsed = write_elapsed_timer.Elapsed().InSecondsF();
LOG(INFO) << "Write speed: " << packets / 1024 / elapsed << " MB/s"; double total_elapsed = total_elapsed_timer.Elapsed().InMillisecondsF();
auto reporter =
SetUpUDPSocketReporter(use_nonblocking_io ? "nonblocking" : "blocking");
reporter.AddResult(kMetricElapsedTimeMs, total_elapsed);
reporter.AddResult(kMetricWriteSpeedBytesPerSecond,
packets * 1024 / write_elapsed);
} }
TEST_F(UDPSocketPerfTest, Write) { TEST_F(UDPSocketPerfTest, Write) {
base::PerfTimeLogger timer("UDP_socket_write");
WriteBenchmark(false); WriteBenchmark(false);
} }
TEST_F(UDPSocketPerfTest, WriteNonBlocking) { TEST_F(UDPSocketPerfTest, WriteNonBlocking) {
base::PerfTimeLogger timer("UDP_socket_write_nonblocking");
WriteBenchmark(true); WriteBenchmark(true);
} }
......
...@@ -39,7 +39,7 @@ ...@@ -39,7 +39,7 @@
#include "net/url_request/url_request_test_util.h" #include "net/url_request/url_request_test_util.h"
#include "testing/gmock/include/gmock/gmock.h" #include "testing/gmock/include/gmock/gmock.h"
#include "testing/gtest/include/gtest/gtest.h" #include "testing/gtest/include/gtest/gtest.h"
#include "testing/perf/perf_test.h" #include "testing/perf/perf_result_reporter.h"
#include "url/gurl.h" #include "url/gurl.h"
using testing::_; using testing::_;
...@@ -62,6 +62,20 @@ const char kHelloAltSvcResponse[] = "Hello from QUIC Server"; ...@@ -62,6 +62,20 @@ const char kHelloAltSvcResponse[] = "Hello from QUIC Server";
const char kHelloOriginResponse[] = "Hello from TCP Server"; const char kHelloOriginResponse[] = "Hello from TCP Server";
const int kHelloStatus = 200; const int kHelloStatus = 200;
static constexpr char kMetricPrefixURLRequestQuick[] = "URLRequestQuic.";
static constexpr char kMetricRequestTimeMs[] = "request_time";
static constexpr char kMetricActiveQuicJobsCount[] = "active_quic_jobs";
static constexpr char kMetricActiveQuicSessionsCount[] = "active_quic_sessions";
perf_test::PerfResultReporter SetUpURLRequestQuicReporter(
const std::string& story) {
perf_test::PerfResultReporter reporter(kMetricPrefixURLRequestQuick, story);
reporter.RegisterImportantMetric(kMetricRequestTimeMs, "ms");
reporter.RegisterImportantMetric(kMetricActiveQuicJobsCount, "count");
reporter.RegisterImportantMetric(kMetricActiveQuicSessionsCount, "count");
return reporter;
}
std::unique_ptr<test_server::HttpResponse> HandleRequest( std::unique_ptr<test_server::HttpResponse> HandleRequest(
const test_server::HttpRequest& request) { const test_server::HttpRequest& request) {
std::unique_ptr<test_server::BasicHttpResponse> http_response( std::unique_ptr<test_server::BasicHttpResponse> http_response(
...@@ -78,16 +92,6 @@ std::unique_ptr<test_server::HttpResponse> HandleRequest( ...@@ -78,16 +92,6 @@ std::unique_ptr<test_server::HttpResponse> HandleRequest(
return std::move(http_response); return std::move(http_response);
} }
void PrintPerfTest(const std::string& name,
int value,
const std::string& unit) {
const ::testing::TestInfo* test_info =
::testing::UnitTest::GetInstance()->current_test_info();
perf_test::PrintResult(test_info->test_case_name(),
std::string(".") + test_info->name(), name,
static_cast<double>(value), unit, true);
}
class URLRequestQuicPerfTest : public ::testing::Test { class URLRequestQuicPerfTest : public ::testing::Test {
protected: protected:
URLRequestQuicPerfTest() URLRequestQuicPerfTest()
...@@ -221,7 +225,9 @@ TEST_F(URLRequestQuicPerfTest, TestGetRequest) { ...@@ -221,7 +225,9 @@ TEST_F(URLRequestQuicPerfTest, TestGetRequest) {
} }
} }
base::TimeTicks end = base::TimeTicks::Now(); base::TimeTicks end = base::TimeTicks::Now();
PrintPerfTest("time", (end - start).InMilliseconds() / kNumRequest, "ms"); auto reporter = SetUpURLRequestQuicReporter("get");
reporter.AddResult(kMetricRequestTimeMs,
(end - start).InMillisecondsF() / kNumRequest);
EXPECT_TRUE(quic_succeeded); EXPECT_TRUE(quic_succeeded);
base::trace_event::MemoryDumpManager::GetInstance()->SetupForTracing( base::trace_event::MemoryDumpManager::GetInstance()->SetupForTracing(
...@@ -259,11 +265,9 @@ TEST_F(URLRequestQuicPerfTest, TestGetRequest) { ...@@ -259,11 +265,9 @@ TEST_F(URLRequestQuicPerfTest, TestGetRequest) {
base::trace_event::MemoryAllocatorDump::kUnitsObjects, base::trace_event::MemoryAllocatorDump::kUnitsObjects,
0); 0);
PrintPerfTest("active_quic_jobs", 0, "count");
CheckScalarInDump(quic_stream_factory_dump, "all_sessions", CheckScalarInDump(quic_stream_factory_dump, "all_sessions",
base::trace_event::MemoryAllocatorDump::kUnitsObjects, base::trace_event::MemoryAllocatorDump::kUnitsObjects,
1); 1);
PrintPerfTest("active_quic_sessions", 1, "count");
std::string stream_factory_dump_name = base::StringPrintf( std::string stream_factory_dump_name = base::StringPrintf(
"net/http_network_session_0x%" PRIxPTR "/stream_factory", "net/http_network_session_0x%" PRIxPTR "/stream_factory",
...@@ -271,7 +275,6 @@ TEST_F(URLRequestQuicPerfTest, TestGetRequest) { ...@@ -271,7 +275,6 @@ TEST_F(URLRequestQuicPerfTest, TestGetRequest) {
context->http_transaction_factory()->GetSession())); context->http_transaction_factory()->GetSession()));
ASSERT_EQ(0u, allocator_dumps.count(stream_factory_dump_name)); ASSERT_EQ(0u, allocator_dumps.count(stream_factory_dump_name));
quit_closure.Run(); quit_closure.Run();
}; };
base::trace_event::MemoryDumpManager::GetInstance()->CreateProcessDump( base::trace_event::MemoryDumpManager::GetInstance()->CreateProcessDump(
args, args,
......
...@@ -8,8 +8,9 @@ ...@@ -8,8 +8,9 @@
#include <vector> #include <vector>
#include "base/stl_util.h" #include "base/stl_util.h"
#include "base/test/perf_time_logger.h" #include "base/timer/elapsed_timer.h"
#include "testing/gtest/include/gtest/gtest.h" #include "testing/gtest/include/gtest/gtest.h"
#include "testing/perf/perf_result_reporter.h"
namespace net { namespace net {
...@@ -19,13 +20,23 @@ const int kIterations = 100000; ...@@ -19,13 +20,23 @@ const int kIterations = 100000;
const int kLongPayloadSize = 1 << 16; const int kLongPayloadSize = 1 << 16;
const char kMaskingKey[] = "\xFE\xED\xBE\xEF"; const char kMaskingKey[] = "\xFE\xED\xBE\xEF";
static constexpr char kMetricPrefixWebSocketFrame[] = "WebSocketFrameMask.";
static constexpr char kMetricMaskTimeMs[] = "mask_time";
perf_test::PerfResultReporter SetUpWebSocketFrameMaskReporter(
const std::string& story) {
perf_test::PerfResultReporter reporter(kMetricPrefixWebSocketFrame, story);
reporter.RegisterImportantMetric(kMetricMaskTimeMs, "ms");
return reporter;
}
static_assert(base::size(kMaskingKey) == static_assert(base::size(kMaskingKey) ==
WebSocketFrameHeader::kMaskingKeyLength + 1, WebSocketFrameHeader::kMaskingKeyLength + 1,
"incorrect masking key size"); "incorrect masking key size");
class WebSocketFrameTestMaskBenchmark : public ::testing::Test { class WebSocketFrameTestMaskBenchmark : public ::testing::Test {
protected: protected:
void Benchmark(const char* const name, void Benchmark(const char* const story,
const char* const payload, const char* const payload,
size_t size) { size_t size) {
std::vector<char> scratch(payload, payload + size); std::vector<char> scratch(payload, payload + size);
...@@ -33,24 +44,24 @@ class WebSocketFrameTestMaskBenchmark : public ::testing::Test { ...@@ -33,24 +44,24 @@ class WebSocketFrameTestMaskBenchmark : public ::testing::Test {
std::copy(kMaskingKey, std::copy(kMaskingKey,
kMaskingKey + WebSocketFrameHeader::kMaskingKeyLength, kMaskingKey + WebSocketFrameHeader::kMaskingKeyLength,
masking_key.key); masking_key.key);
base::PerfTimeLogger timer(name); auto reporter = SetUpWebSocketFrameMaskReporter(story);
base::ElapsedTimer timer;
for (int x = 0; x < kIterations; ++x) { for (int x = 0; x < kIterations; ++x) {
MaskWebSocketFramePayload( MaskWebSocketFramePayload(
masking_key, x % size, &scratch.front(), scratch.size()); masking_key, x % size, &scratch.front(), scratch.size());
} }
timer.Done(); reporter.AddResult(kMetricMaskTimeMs, timer.Elapsed().InMillisecondsF());
} }
}; };
TEST_F(WebSocketFrameTestMaskBenchmark, BenchmarkMaskShortPayload) { TEST_F(WebSocketFrameTestMaskBenchmark, BenchmarkMaskShortPayload) {
static const char kShortPayload[] = "Short Payload"; static const char kShortPayload[] = "Short Payload";
Benchmark("Frame_mask_short_payload", kShortPayload, Benchmark("short_payload", kShortPayload, base::size(kShortPayload));
base::size(kShortPayload));
} }
TEST_F(WebSocketFrameTestMaskBenchmark, BenchmarkMaskLongPayload) { TEST_F(WebSocketFrameTestMaskBenchmark, BenchmarkMaskLongPayload) {
std::vector<char> payload(kLongPayloadSize, 'a'); std::vector<char> payload(kLongPayloadSize, 'a');
Benchmark("Frame_mask_long_payload", &payload.front(), payload.size()); Benchmark("long_payload", &payload.front(), payload.size());
} }
// A 31-byte payload is guaranteed to do 7 byte mask operations and 3 vector // A 31-byte payload is guaranteed to do 7 byte mask operations and 3 vector
...@@ -58,7 +69,7 @@ TEST_F(WebSocketFrameTestMaskBenchmark, BenchmarkMaskLongPayload) { ...@@ -58,7 +69,7 @@ TEST_F(WebSocketFrameTestMaskBenchmark, BenchmarkMaskLongPayload) {
// back to the byte-only code path and do 31 byte mask operations. // back to the byte-only code path and do 31 byte mask operations.
TEST_F(WebSocketFrameTestMaskBenchmark, Benchmark31BytePayload) { TEST_F(WebSocketFrameTestMaskBenchmark, Benchmark31BytePayload) {
std::vector<char> payload(31, 'a'); std::vector<char> payload(31, 'a');
Benchmark("Frame_mask_31_payload", &payload.front(), payload.size()); Benchmark("31_payload", &payload.front(), payload.size());
} }
} // namespace } // namespace
......
...@@ -59,6 +59,7 @@ GTEST_CONVERSION_WHITELIST = [ ...@@ -59,6 +59,7 @@ GTEST_CONVERSION_WHITELIST = [
'latency_perftests', 'latency_perftests',
'load_library_perf_tests', 'load_library_perf_tests',
'media_perftests', 'media_perftests',
'net_perftests',
'views_perftests', 'views_perftests',
'viz_perftests', 'viz_perftests',
'xr.vr.common_perftests', 'xr.vr.common_perftests',
......
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