Certificate Transparency: Collect metrics on age of SCT vs STH

components/certificate_transparency/single_tree_tracker_unittest.cc

 // Copyright 2016 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "components/certificate_transparency/single_tree_tracker.h"
 
 #include <string>
 #include <utility>
 
 #include "base/strings/string_piece.h"
+#include "base/test/histogram_tester.h"
 #include "net/cert/ct_log_verifier.h"
 #include "net/cert/ct_serialization.h"
 #include "net/cert/signed_certificate_timestamp.h"
 #include "net/cert/signed_tree_head.h"
 #include "net/cert/x509_certificate.h"
 #include "net/test/ct_test_util.h"
 #include "testing/gtest/include/gtest/gtest.h"
 
 namespace certificate_transparency {
+using internal::kCanCheckForInclusionHistogramName;

[Ryan Sleevi, 2016/07/20 20:34:00]

Newline

[Eran Messeri, 2016/07/21 17:53:43]

Done.

 
 namespace {
 
 bool GetOldSignedTreeHead(net::ct::SignedTreeHead* sth) {
   sth->version = net::ct::SignedTreeHead::V1;
   sth->timestamp = base::Time::UnixEpoch() +
                    base::TimeDelta::FromMilliseconds(INT64_C(1348589665525));
   sth->tree_size = 12u;
 
   const uint8_t kOldSTHRootHash[] = {
@@ skipping 38 matching lines @@
  protected:
   scoped_refptr<const net::CTLogVerifier> log_;
   std::unique_ptr<SingleTreeTracker> tree_tracker_;
   scoped_refptr<net::X509Certificate> chain_;
   scoped_refptr<net::ct::SignedCertificateTimestamp> cert_sct_;
 };
 
 // Test that an SCT is classified as pending for a newer STH if the
 // SingleTreeTracker has not seen any STHs so far.
 TEST_F(SingleTreeTrackerTest, CorrectlyClassifiesUnobservedSCTNoSTH) {
+  base::HistogramTester histograms;
   // First make sure the SCT has not been observed at all.
   EXPECT_EQ(
       SingleTreeTracker::SCT_NOT_OBSERVED,
       tree_tracker_->GetLogEntryInclusionStatus(chain_.get(), cert_sct_.get()));
 
   tree_tracker_->OnSCTVerified(chain_.get(), cert_sct_.get());
 
   // Since no STH was provided to the tree_tracker_ the status should be that
   // the SCT is pending a newer STH.
   EXPECT_EQ(
       SingleTreeTracker::SCT_PENDING_NEWER_STH,
       tree_tracker_->GetLogEntryInclusionStatus(chain_.get(), cert_sct_.get()));
+
+  // Since there's no valid STH expect nothing was logged to UMA.

[Ryan Sleevi, 2016/07/20 20:34:00]

Grammar: Something feels off on this, most likely punctuation (gut says a comma
between STH and expect)

that said, this could be reworded to be clearer

// Expect nothing to be logged because there's no valid STH.


That said, from a design perspective, it's unclear why you would expect that
nothing's logged if it's pending an STH - I would think that if the histogram is
measuring whether or not you can check for inclusion, you would expect that it
would be logged if you encounter an SCT that you can't check for inclusion
(yet).

[Eran Messeri, 2016/07/21 17:53:43]

Done.
Good point. I've attempted to explain it in the documentation for
LogCanBeCheckedForInclusionToUMA (single_tree_tracker.cc). The gist is that we'd
like to learn how often clients encounter "very new"  SCTs and logging UMA when
a client does not have a valid STH at all would skew the data as it would log
its inability to check inclusion for every SCT observed.

+  histograms.ExpectTotalCount(kCanCheckForInclusionHistogramName, 0);
 }
 
 // Test that an SCT is classified as pending an inclusion check if the
 // SingleTreeTracker has a fresh-enough STH to check inclusion against.
 TEST_F(SingleTreeTrackerTest, CorrectlyClassifiesUnobservedSCTWithRecentSTH) {
+  base::HistogramTester histograms;
   // Provide an STH to the tree_tracker_.
   net::ct::SignedTreeHead sth;
   net::ct::GetSampleSignedTreeHead(&sth);
   tree_tracker_->NewSTHObserved(sth);
 
   // Make sure the SCT status is the same as if there's no STH for
   // this log.
   EXPECT_EQ(
       SingleTreeTracker::SCT_NOT_OBSERVED,
       tree_tracker_->GetLogEntryInclusionStatus(chain_.get(), cert_sct_.get()));
 
   tree_tracker_->OnSCTVerified(chain_.get(), cert_sct_.get());
 
   // The status for this SCT should be 'pending inclusion check' since the STH
   // provided at the beginning of the test is newer than the SCT.
   EXPECT_EQ(
       SingleTreeTracker::SCT_PENDING_INCLUSION_CHECK,
       tree_tracker_->GetLogEntryInclusionStatus(chain_.get(), cert_sct_.get()));
+
+  // Exactly one value should be logged, indicating the SCT
+  // can be checked for inclusion.

[Ryan Sleevi, 2016/07/20 20:34:00]

Similarly, this comment doesn't make sense in the context of the CLs stated
goals.

To me, the non-obvious part is not what you're testing for here, but why you're
testing it, compared with the above test.

[Eran Messeri, 2016/07/21 17:53:43]

Expanded the comment to document why it's expected to have a value emitted to
UMA here.

+  histograms.ExpectTotalCount(kCanCheckForInclusionHistogramName, 1);
+  histograms.ExpectBucketCount(kCanCheckForInclusionHistogramName, true, 1);
 }
 
 // Test that the SingleTreeTracker correctly queues verified SCTs for inclusion
 // checking such that, upon receiving a fresh STH, it changes the SCT's status
 // from pending newer STH to pending inclusion check.
 TEST_F(SingleTreeTrackerTest, CorrectlyUpdatesSCTStatusOnNewSTH) {
+  base::HistogramTester histograms;
   // Report an observed SCT and make sure it's in the pending newer STH
   // state.
   tree_tracker_->OnSCTVerified(chain_.get(), cert_sct_.get());
   EXPECT_EQ(
       SingleTreeTracker::SCT_PENDING_NEWER_STH,
       tree_tracker_->GetLogEntryInclusionStatus(chain_.get(), cert_sct_.get()));
+  histograms.ExpectTotalCount(kCanCheckForInclusionHistogramName, 0);
 
   // Provide with a fresh STH
   net::ct::SignedTreeHead sth;
   net::ct::GetSampleSignedTreeHead(&sth);
   tree_tracker_->NewSTHObserved(sth);
 
   // Test that its status has changed.
   EXPECT_EQ(
       SingleTreeTracker::SCT_PENDING_INCLUSION_CHECK,
       tree_tracker_->GetLogEntryInclusionStatus(chain_.get(), cert_sct_.get()));
+  // Check that no UMA was logged for this case as the histogram is only
+  // supposed to measure the state of newly-observed SCTs, not pending ones.
+  histograms.ExpectTotalCount(kCanCheckForInclusionHistogramName, 0);
 }
 
 // Test that the SingleTreeTracker does not change an SCT's status if an STH
 // from the log it was issued by is observed, but that STH is too old to check
 // inclusion against.
 TEST_F(SingleTreeTrackerTest, DoesNotUpdatesSCTStatusOnOldSTH) {
   // Notify of an SCT and make sure it's in the 'pending newer STH' state.
   tree_tracker_->OnSCTVerified(chain_.get(), cert_sct_.get());
   EXPECT_EQ(
       SingleTreeTracker::SCT_PENDING_NEWER_STH,
       tree_tracker_->GetLogEntryInclusionStatus(chain_.get(), cert_sct_.get()));
 
   // Provide an old STH for the same log.
   net::ct::SignedTreeHead sth;
   GetOldSignedTreeHead(&sth);
   tree_tracker_->NewSTHObserved(sth);
 
   // Make sure the SCT's state hasn't changed.
   EXPECT_EQ(
       SingleTreeTracker::SCT_PENDING_NEWER_STH,
       tree_tracker_->GetLogEntryInclusionStatus(chain_.get(), cert_sct_.get()));
 }
 
+// Test that the SingleTreeTracker correctly logs that an SCT is pending a new
+// STH when it has STH but the observed SCT is newer than that.

[Ryan Sleevi, 2016/07/20 20:34:00]

"than that" is ambiguous.

grammatically, this reads weird, like it's missing punctuation.

[Eran Messeri, 2016/07/21 17:53:43]

Re-worded the comment a bit, removed 'than that' and referred explicitly to the
STH.

+TEST_F(SingleTreeTrackerTest, LogsUMAForNewSCTAndOldSTH) {
+  base::HistogramTester histograms;
+  // Provide an old STH for the same log.
+  net::ct::SignedTreeHead sth;
+  GetOldSignedTreeHead(&sth);
+  tree_tracker_->NewSTHObserved(sth);
+
+  histograms.ExpectTotalCount(kCanCheckForInclusionHistogramName, 0);
+  // Notify of an SCT and make sure it's in the 'pending newer STH' state.
+  tree_tracker_->OnSCTVerified(chain_.get(), cert_sct_.get());

[Ryan Sleevi, 2016/07/20 20:34:00]

newline between 184-185 and 186-187

[Eran Messeri, 2016/07/21 17:53:43]

Done.

+  // Exactly one value should be logged, indicating the SCT cannot be checked
+  // for inclusion as the STH is too old.
+  histograms.ExpectTotalCount(kCanCheckForInclusionHistogramName, 1);
+  histograms.ExpectBucketCount(kCanCheckForInclusionHistogramName, false, 1);
+}
+
 }  // namespace certificate_transparency