Skip to content

Commit

Permalink
Reland of Add metrics for certificate report uploads
Browse files Browse the repository at this point in the history 
One of the tests changed by this CL was flaky (CertificateReportingServiceBrowserTest.
DontSendOldReports). This is now fixed, so relanding the CL.

Original CL: https://codereview.chromium.org/2862453002

When sending certificate reports, we suspect that some content filters, firewalls and
captive portals delay the response indefinitely without sending back any response.
Certificate uploads rely on a response to be received in order to decide whether
to retry uploading the report, so this breaks those assumptions. This CL adds a histogram
to understand how often this happens. In particular, a difference between submitted
reports and the sum of failed and successful reports will indicate that some reports simply
get lost. The histogram also provides insight about how often queued reports are dropped,
which will help us fine tune the queue size and report time-to-live.

A question that came up while discussing this histogram was whether it would be useful
since UMA uploads can also be blocked in a similar way. The answer seems to be yes, as UMA
retries metrics uploads with a different frequency, and it persists metrics uploads whereas
cert reports are not persisted.

Bug: 682933
Change-Id: I09616eaf04854157ddeff8d20d39e18afc705967
Reviewed-on: https://chromium-review.googlesource.com/782642
Commit-Queue: Mustafa Emre Acer <meacer@chromium.org>
Reviewed-by: Ilya Sherman <isherman@chromium.org>
Reviewed-by: Emily Stark <estark@chromium.org>
Reviewed-by: Jialiu Lin <jialiul@chromium.org>
Cr-Commit-Position: refs/heads/master@{#518789}
  • Loading branch information
@meacer
meacer authored and Commit Bot committed Nov 22, 2017
1 parent f2848d1 commit 4228190
Show file tree
Hide file tree
Showing 8 changed files with 272 additions and 3 deletions.
15 changes: 15 additions & 0 deletions chrome/browser/safe_browsing/certificate_reporting_service.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -38,13 +38,22 @@ void RecordUMAOnFailure(int net_error) {
UMA_HISTOGRAM_SPARSE_SLOWLY("SSL.CertificateErrorReportFailure", -net_error);
}

void RecordUMAEvent(CertificateReportingService::ReportOutcome outcome) {
UMA_HISTOGRAM_ENUMERATION(
CertificateReportingService::kReportEventHistogram, outcome,
CertificateReportingService::ReportOutcome::EVENT_COUNT);
}

void CleanupOnIOThread(
std::unique_ptr<CertificateReportingService::Reporter> reporter) {
reporter.reset();
}

} // namespace

const char CertificateReportingService::kReportEventHistogram[] =
"SSL.CertificateErrorReportEvent";

CertificateReportingService::BoundedReportList::BoundedReportList(
size_t max_size)
: max_size_(max_size) {
Expand All @@ -62,10 +71,12 @@ void CertificateReportingService::BoundedReportList::Add(const Report& item) {
const Report& last = items_.back();
if (item.creation_time <= last.creation_time) {
// Report older than the oldest item in the queue, ignore.
RecordUMAEvent(ReportOutcome::DROPPED_OR_IGNORED);
return;
}
// Reached the maximum item count, remove the oldest item.
items_.pop_back();
RecordUMAEvent(ReportOutcome::DROPPED_OR_IGNORED);
}
items_.push_back(item);
std::sort(items_.begin(), items_.end(), ReportCompareFunc);
Expand Down Expand Up @@ -115,6 +126,7 @@ void CertificateReportingService::Reporter::SendPending() {
for (Report& report : items) {
if (report.creation_time < now - report_ttl_) {
// Report too old, ignore.
RecordUMAEvent(ReportOutcome::DROPPED_OR_IGNORED);
continue;
}
if (!report.is_retried) {
Expand Down Expand Up @@ -145,6 +157,7 @@ void CertificateReportingService::Reporter::SendInternal(
const CertificateReportingService::Report& report) {
DCHECK_CURRENTLY_ON(content::BrowserThread::IO);
inflight_reports_.insert(std::make_pair(report.report_id, report));
RecordUMAEvent(ReportOutcome::SUBMITTED);
error_reporter_->SendExtendedReportingReport(
report.serialized_report,
base::Bind(&CertificateReportingService::Reporter::SuccessCallback,
Expand All @@ -160,6 +173,7 @@ void CertificateReportingService::Reporter::ErrorCallback(
int http_response_code) {
DCHECK_CURRENTLY_ON(content::BrowserThread::IO);
RecordUMAOnFailure(net_error);
RecordUMAEvent(ReportOutcome::FAILED);
if (retries_enabled_) {
auto it = inflight_reports_.find(report_id);
DCHECK(it != inflight_reports_.end());
Expand All @@ -170,6 +184,7 @@ void CertificateReportingService::Reporter::ErrorCallback(

void CertificateReportingService::Reporter::SuccessCallback(int report_id) {
DCHECK_CURRENTLY_ON(content::BrowserThread::IO);
RecordUMAEvent(ReportOutcome::SUCCESSFUL);
CHECK_GT(inflight_reports_.erase(report_id), 0u);
}

Expand Down
23 changes: 23 additions & 0 deletions chrome/browser/safe_browsing/certificate_reporting_service.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -55,6 +55,26 @@ class SafeBrowsingService;
// extended reporting preferences.
class CertificateReportingService : public KeyedService {
public:
// Events for UMA. Do not rename or remove values, add new values to the end.
// Public for testing.
enum class ReportOutcome {
// A report is submitted. This includes failed and successful uploads as
// well as uploads that never return a response.
SUBMITTED = 0,
// A report submission failed, either because of a net error or a non-HTTP
// 200 response from the server.
FAILED = 1,
// A report submission was successfully sent, receiving an HTTP 200 response
// from the server.
SUCCESSFUL = 2,
// A report was dropped from the reporting queue because it was older
// than report TTL, or it was ignored because the queue was full and the
// report was older than the oldest report in the queue. Does not include
// reports that were cleared because of a SafeBrowsing preference change.
DROPPED_OR_IGNORED = 3,
EVENT_COUNT = 4
};

// Represents a report to be sent.
struct Report {
int report_id;
Expand Down Expand Up @@ -153,6 +173,9 @@ class CertificateReportingService : public KeyedService {
DISALLOW_COPY_AND_ASSIGN(Reporter);
};

// Public for testing.
static const char kReportEventHistogram[];

CertificateReportingService(
safe_browsing::SafeBrowsingService* safe_browsing_service,
scoped_refptr<net::URLRequestContextGetter> url_request_context_getter,
Expand Down
70 changes: 69 additions & 1 deletion chrome/browser/safe_browsing/certificate_reporting_service_browsertest.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -38,6 +38,7 @@

using certificate_reporting_test_utils::CertificateReportingServiceTestHelper;
using certificate_reporting_test_utils::CertificateReportingServiceObserver;
using certificate_reporting_test_utils::EventHistogramTester;
using certificate_reporting_test_utils::ReportExpectation;
using certificate_reporting_test_utils::RetryStatus;

Expand Down Expand Up @@ -87,6 +88,9 @@ class CertificateReportingServiceBrowserTest : public InProcessBrowserTest {
->SetServiceResetCallbackForTesting(
base::Bind(&CertificateReportingServiceObserver::OnServiceReset,
base::Unretained(&service_observer_)));

event_histogram_tester_.reset(new EventHistogramTester());
InProcessBrowserTest::SetUpOnMainThread();
}

void TearDownOnMainThread() override {
Expand All @@ -104,6 +108,8 @@ class CertificateReportingServiceBrowserTest : public InProcessBrowserTest {
} else {
histogram_tester_.ExpectTotalCount(kFailedReportHistogram, 0);
}

event_histogram_tester_.reset();
}

void SetUpCommandLine(base::CommandLine* command_line) override {
Expand Down Expand Up @@ -174,6 +180,10 @@ class CertificateReportingServiceBrowserTest : public InProcessBrowserTest {
browser()->profile());
}

EventHistogramTester* event_histogram_tester() {
return event_histogram_tester_.get();
}

private:
// Checks that the serialized reports in |received_reports| have the same
// hostnames as |expected_hostnames|.
Expand All @@ -199,6 +209,11 @@ class CertificateReportingServiceBrowserTest : public InProcessBrowserTest {
CertificateReportingServiceObserver service_observer_;

base::HistogramTester histogram_tester_;
// Histogram tester for reporting events. This is a member instead of a local
// so that we can check the histogram after the test teardown. At that point
// all in flight reports should be completed or deleted because
// of CleanUpOnIOThread().
std::unique_ptr<EventHistogramTester> event_histogram_tester_;

DISALLOW_COPY_AND_ASSIGN(CertificateReportingServiceBrowserTest);
};
Expand All @@ -215,6 +230,8 @@ IN_PROC_BROWSER_TEST_F(CertificateReportingServiceBrowserTest,
// Send a report. Test teardown checks for created and in-flight requests. If
// a report was incorrectly sent, the test will fail.
SendReport("no-report");

event_histogram_tester()->SetExpectedValues(0, 0, 0, 0);
}

// Tests that report send attempts are not cancelled when extended reporting is
Expand All @@ -235,6 +252,10 @@ IN_PROC_BROWSER_TEST_F(CertificateReportingServiceBrowserTest,
SendReport("report0");
test_helper()->WaitForRequestsDestroyed(
ReportExpectation::Successful({{"report0", RetryStatus::NOT_RETRIED}}));

// report0 was successfully submitted.
event_histogram_tester()->SetExpectedValues(
1 /* submitted */, 0 /* failed */, 1 /* successful */, 0 /* dropped */);
}

// Tests that report send attempts are not cancelled when extended reporting is
Expand Down Expand Up @@ -279,6 +300,12 @@ IN_PROC_BROWSER_TEST_F(CertificateReportingServiceBrowserTest,
// nothing should be sent this time. If any report is sent, test teardown
// will catch it.
SendPendingReports();

// report0 was submitted twice, failed once, succeeded once.
// report1 was submitted twice, failed once, succeeded once.
// report2 was submitted once, succeeded once.
event_histogram_tester()->SetExpectedValues(
5 /* submitted */, 2 /* failed */, 3 /* successful */, 0 /* dropped */);
}

// Opting in then opting out of extended reporting should clear the pending
Expand All @@ -304,6 +331,10 @@ IN_PROC_BROWSER_TEST_F(CertificateReportingServiceBrowserTest,

// Send pending reports. No reports should be observed during test teardown.
SendPendingReports();

// report0 was submitted once and failed once.
event_histogram_tester()->SetExpectedValues(
1 /* submitted */, 1 /* failed */, 0 /* successful */, 0 /* dropped */);
}

// Opting out, then in, then out of extended reporting should work as expected.
Expand Down Expand Up @@ -343,6 +374,11 @@ IN_PROC_BROWSER_TEST_F(CertificateReportingServiceBrowserTest,
// Send pending reports. Nothing should be sent since there aren't any
// pending reports. If any report is sent, test teardown will catch it.
SendPendingReports();

// report0 was submitted once and failed once.
// report1 was never submitted.
event_histogram_tester()->SetExpectedValues(
1 /* submitted */, 1 /* failed */, 0 /* successful */, 0 /* dropped */);
}

// Disabling SafeBrowsing should clear pending reports queue in
Expand All @@ -357,7 +393,7 @@ IN_PROC_BROWSER_TEST_F(CertificateReportingServiceBrowserTest,
test_helper()->SetFailureMode(
certificate_reporting_test_utils::ReportSendingResult::REPORTS_FAIL);

// Send a delayed report.
// Send a report.
SendReport("report0");
test_helper()->WaitForRequestsDestroyed(
ReportExpectation::Failed({{"report0", RetryStatus::NOT_RETRIED}}));
Expand All @@ -381,6 +417,11 @@ IN_PROC_BROWSER_TEST_F(CertificateReportingServiceBrowserTest,
SendPendingReports();
test_helper()->WaitForRequestsDestroyed(
ReportExpectation::Successful({{"report1", RetryStatus::RETRIED}}));

// report0 was submitted once, failed once, then cleared.
// report1 was submitted twice, failed once, succeeded once.
event_histogram_tester()->SetExpectedValues(
3 /* submitted */, 2 /* failed */, 1 /* successful */, 0 /* dropped */);
}

// CertificateReportingService should ignore reports older than the report TTL.
Expand Down Expand Up @@ -454,6 +495,13 @@ IN_PROC_BROWSER_TEST_F(CertificateReportingServiceBrowserTest,
SendReport("report3");
test_helper()->WaitForRequestsDestroyed(
ReportExpectation::Successful({{"report3", RetryStatus::NOT_RETRIED}}));

// report0 was submitted once, failed once, dropped once.
// report1 was submitted twice, failed twice, dropped once.
// report2 was submitted twice, failed twice, dropped once.
// report3 was submitted once, successful once.
event_histogram_tester()->SetExpectedValues(
6 /* submitted */, 5 /* failed */, 1 /* successful */, 3 /* dropped */);
}

// CertificateReportingService should drop old reports from its pending report
Expand Down Expand Up @@ -528,6 +576,13 @@ IN_PROC_BROWSER_TEST_F(CertificateReportingServiceBrowserTest,
SendPendingReports();
test_helper()->WaitForRequestsDestroyed(ReportExpectation::Successful(
{{"report2", RetryStatus::RETRIED}, {"report3", RetryStatus::RETRIED}}));

// report0 was submitted once, failed once, dropped once.
// report1 was submitted twice, failed twice, dropped once.
// report2 was submitted thrice, failed twice, succeeded once.
// report3 was submitted thrice, failed twice, succeeded once.
event_histogram_tester()->SetExpectedValues(
9 /* submitted */, 7 /* failed */, 2 /* successful */, 2 /* dropped */);
}

IN_PROC_BROWSER_TEST_F(CertificateReportingServiceBrowserTest,
Expand All @@ -551,6 +606,10 @@ IN_PROC_BROWSER_TEST_F(CertificateReportingServiceBrowserTest,
test_helper()->ResumeDelayedRequest();
test_helper()->WaitForRequestsDestroyed(
ReportExpectation::Delayed({{"report0", RetryStatus::NOT_RETRIED}}));

// report0 was submitted once and succeeded once.
event_histogram_tester()->SetExpectedValues(
1 /* submitted */, 0 /* failed */, 1 /* successful */, 0 /* dropped */);
}

// Same as above, but the service is shut down before resuming the delayed
Expand All @@ -575,6 +634,10 @@ IN_PROC_BROWSER_TEST_F(CertificateReportingServiceBrowserTest,
test_helper()->ResumeDelayedRequest();
test_helper()->WaitForRequestsDestroyed(
ReportExpectation::Delayed({{"report0", RetryStatus::NOT_RETRIED}}));

// report0 was submitted once and never completed since the service shut down.
event_histogram_tester()->SetExpectedValues(
1 /* submitted */, 0 /* failed */, 0 /* successful */, 0 /* dropped */);
}

// Trigger a delayed report, then disable Safebrowsing. Certificate reporting
Expand Down Expand Up @@ -615,6 +678,11 @@ IN_PROC_BROWSER_TEST_F(CertificateReportingServiceBrowserTest, Delayed_Reset) {
test_helper()->ResumeDelayedRequest();
test_helper()->WaitForRequestsDestroyed(
ReportExpectation::Delayed({{"report1", RetryStatus::NOT_RETRIED}}));

// report0 was submitted once and delayed, then cleared.
// report1 was submitted once and delayed, then succeeded.
event_histogram_tester()->SetExpectedValues(
2 /* submitted */, 0 /* failed */, 1 /* successful */, 0 /* dropped */);
}

} // namespace safe_browsing
44 changes: 44 additions & 0 deletions chrome/browser/safe_browsing/certificate_reporting_service_test_utils.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -453,4 +453,48 @@ void CertificateReportingServiceTestHelper::ExpectNoRequests(
}
}

EventHistogramTester::EventHistogramTester() {}

EventHistogramTester::~EventHistogramTester() {
if (submitted_) {
histogram_tester_.ExpectBucketCount(
CertificateReportingService::kReportEventHistogram,
static_cast<int>(CertificateReportingService::ReportOutcome::SUBMITTED),
submitted_);
}
if (failed_) {
histogram_tester_.ExpectBucketCount(
CertificateReportingService::kReportEventHistogram,
static_cast<int>(CertificateReportingService::ReportOutcome::FAILED),
failed_);
}
if (successful_) {
histogram_tester_.ExpectBucketCount(
CertificateReportingService::kReportEventHistogram,
static_cast<int>(
CertificateReportingService::ReportOutcome::SUCCESSFUL),
successful_);
}
if (dropped_) {
histogram_tester_.ExpectBucketCount(
CertificateReportingService::kReportEventHistogram,
static_cast<int>(
CertificateReportingService::ReportOutcome::DROPPED_OR_IGNORED),
dropped_);
}
histogram_tester_.ExpectTotalCount(
CertificateReportingService::kReportEventHistogram,
submitted_ + failed_ + successful_ + dropped_);
}

void EventHistogramTester::SetExpectedValues(int submitted,
int failed,
int successful,
int dropped) {
submitted_ = submitted;
failed_ = failed;
successful_ = successful;
dropped_ = dropped;
}

} // namespace certificate_reporting_test_utils
23 changes: 23 additions & 0 deletions chrome/browser/safe_browsing/certificate_reporting_service_test_utils.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@
#include "base/macros.h"
#include "base/run_loop.h"
#include "base/sequence_checker.h"
#include "base/test/histogram_tester.h"
#include "chrome/browser/safe_browsing/certificate_reporting_service.h"
#include "content/public/test/test_browser_thread.h"
#include "content/public/test/test_browser_thread_bundle.h"
Expand Down Expand Up @@ -242,6 +243,28 @@ class CertificateReportingServiceTestHelper {
DISALLOW_COPY_AND_ASSIGN(CertificateReportingServiceTestHelper);
};

// Class to test reporting events histogram for CertificateReportingService.
// We can't use a simple HistogramTester, as we need to wait until test teardown
// to check the histogram contents. This ensures that all in-flight requests
// are torn down by the time we check the histograms.
class EventHistogramTester {
public:
EventHistogramTester();
~EventHistogramTester();

void SetExpectedValues(int submitted,
int failed,
int successful,
int dropped);

private:
int submitted_ = 0;
int failed_ = 0;
int successful_ = 0;
int dropped_ = 0;
base::HistogramTester histogram_tester_;
};

} // namespace certificate_reporting_test_utils

#endif // CHROME_BROWSER_SAFE_BROWSING_CERTIFICATE_REPORTING_SERVICE_TEST_UTILS_H_
Loading

0 comments on commit 4228190

Please sign in to comment.