Magic-Mirror/gecko-dev
1
0
Fork 0
mirror of https://github.com/mozilla/gecko-dev.git synced 2024-10-07 18:04:46 +00:00
Code Issues Actions Packages Projects Releases Wiki Activity

bug 1602641 - add CRLite/OCSP timing comparison telemetry r=jcj

Browse Source 
To evaluate the performance impact of CRLite over OCSP, we need to measure when
CRLite is (presumably) faster and by how much. To do this, we measure the
duration of the respective operations and when both occur for the same
verification, we make a note in the appropriate histogram of how much faster
one was than the other.

data-review+ was already given in bug 1488865 comment 5

Differential Revision: https://phabricator.services.mozilla.com/D56508

--HG--
extra : moz-landing-system : lando
This commit is contained in:
Dana Keeler 2019-12-10 23:32:51 +00:00
parent e891cab2a3
commit 314ecf40aa
6 changed files with 106 additions and 25 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

4
security/certverifier/CertVerifier.cpp
View File

@ -644,7 +644,7 @@ Result CertVerifier::VerifyCert(
pinningTelemetryInfo->Reset();
}
if (crliteInfo) {
*crliteInfo = CRLiteTelemetryInfo::NeverChecked;
crliteInfo->Reset();
}
NSSCertDBTrustDomain trustDomain(
@ -730,7 +730,7 @@ Result CertVerifier::VerifyCert(
pinningTelemetryInfo->Reset();
}
if (crliteInfo) {
*crliteInfo = CRLiteTelemetryInfo::NeverChecked;
crliteInfo->Reset();
}
NSSCertDBTrustDomain trustDomain(

17
security/certverifier/CertVerifier.h
View File

@ -140,7 +140,7 @@ class DelegatedCredentialInfo {
uint32_t authKeyBits;
};
enum class CRLiteTelemetryInfo {
enum class CRLiteLookupResult {
NeverChecked = 0,
FilterNotAvailable = 1,
IssuerNotEnrolled = 2,
@ -150,6 +150,21 @@ enum class CRLiteTelemetryInfo {
LibraryFailure = 6,
};
class CRLiteTelemetryInfo {
public:
CRLiteTelemetryInfo() : mLookupResult(CRLiteLookupResult::NeverChecked) {}
void Reset() {
mLookupResult = CRLiteLookupResult::NeverChecked;
mCRLiteFasterThanOCSPMillis.reset();
mOCSPFasterThanCRLiteMillis.reset();
}
CRLiteLookupResult mLookupResult;
Maybe<double> mCRLiteFasterThanOCSPMillis;
Maybe<double> mOCSPFasterThanCRLiteMillis;
};
class NSSCertDBTrustDomain;
class CertVerifier {

45
security/certverifier/NSSCertDBTrustDomain.cpp
View File

@ -612,6 +612,7 @@ Result NSSCertDBTrustDomain::CheckRevocation(
MOZ_LOG(gCertVerifierLog, LogLevel::Debug,
("NSSCertDBTrustDomain: Top of CheckRevocation\n"));
Maybe<TimeDuration> crliteLookupDuration;
#ifdef MOZ_NEW_CERT_STORAGE
if (endEntityOrCA == EndEntityOrCA::MustBeEndEntity &&
mCRLiteMode != CRLiteMode::Disabled) {
@ -629,14 +630,17 @@ Result NSSCertDBTrustDomain::CheckRevocation(
certID.serialNumber.GetLength());
uint64_t filterTimestamp;
int16_t crliteRevocationState;
TimeStamp crliteLookupBefore = TimeStamp::Now();
nsresult rv = mCertStorage->GetCRLiteRevocationState(
issuerBytes, issuerSubjectPublicKeyInfoBytes, serialNumberBytes,
&filterTimestamp, &crliteRevocationState);
TimeStamp crliteLookupAfter = TimeStamp::Now();
if (NS_FAILED(rv)) {
MOZ_LOG(gCertVerifierLog, LogLevel::Debug,
("NSSCertDBTrustDomain::CheckRevocation: CRLite call failed"));
if (mCRLiteTelemetryInfo) {
*mCRLiteTelemetryInfo = CRLiteTelemetryInfo::LibraryFailure;
mCRLiteTelemetryInfo->mLookupResult =
CRLiteLookupResult::LibraryFailure;
}
if (mCRLiteMode == CRLiteMode::Enforce) {
return Result::FATAL_ERROR_LIBRARY_FAILURE;
@ -649,6 +653,13 @@ Result NSSCertDBTrustDomain::CheckRevocation(
// The cast is to silence warnings on compilers where uint64_t is
// an unsigned long as opposed to an unsigned long long.
static_cast<unsigned long long>(filterTimestamp)));
// If and only if the filter timestamp is non-zero and we didn't get a
// "not enrolled" result, we performed a full CRLite lookup.
// We only want to note the lookup duration when we actually did a lookup.
if (filterTimestamp != 0 &&
crliteRevocationState != nsICertStorage::STATE_NOT_ENROLLED) {
crliteLookupDuration.emplace(crliteLookupAfter - crliteLookupBefore);
}
Time filterTimestampTime(TimeFromEpochInSeconds(filterTimestamp));
// We can only use this result if this certificate's `notBefore` time
// (i.e. the beginning of its validity period) is older than what cert
@ -658,7 +669,8 @@ Result NSSCertDBTrustDomain::CheckRevocation(
if (certValidityPeriodBeginning <= filterTimestampTime &&
crliteRevocationState == nsICertStorage::STATE_ENFORCE) {
if (mCRLiteTelemetryInfo) {
*mCRLiteTelemetryInfo = CRLiteTelemetryInfo::CertificateRevoked;
mCRLiteTelemetryInfo->mLookupResult =
CRLiteLookupResult::CertificateRevoked;
}
if (mCRLiteMode == CRLiteMode::Enforce) {
MOZ_LOG(
@ -675,7 +687,8 @@ Result NSSCertDBTrustDomain::CheckRevocation(
if (crliteRevocationState == nsICertStorage::STATE_NOT_ENROLLED) {
if (mCRLiteTelemetryInfo) {
*mCRLiteTelemetryInfo = CRLiteTelemetryInfo::IssuerNotEnrolled;
mCRLiteTelemetryInfo->mLookupResult =
CRLiteLookupResult::IssuerNotEnrolled;
}
MOZ_LOG(gCertVerifierLog, LogLevel::Debug,
("NSSCertDBTrustDomain::CheckRevocation: issuer not enrolled"));
@ -684,17 +697,20 @@ Result NSSCertDBTrustDomain::CheckRevocation(
MOZ_LOG(gCertVerifierLog, LogLevel::Debug,
("NSSCertDBTrustDomain::CheckRevocation: no timestamp"));
if (mCRLiteTelemetryInfo) {
*mCRLiteTelemetryInfo = CRLiteTelemetryInfo::FilterNotAvailable;
mCRLiteTelemetryInfo->mLookupResult =
CRLiteLookupResult::FilterNotAvailable;
}
} else if (certValidityPeriodBeginning > filterTimestampTime) {
MOZ_LOG(gCertVerifierLog, LogLevel::Debug,
("NSSCertDBTrustDomain::CheckRevocation: cert too new"));
if (mCRLiteTelemetryInfo) {
*mCRLiteTelemetryInfo = CRLiteTelemetryInfo::CertificateTooNew;
mCRLiteTelemetryInfo->mLookupResult =
CRLiteLookupResult::CertificateTooNew;
}
} else if (crliteRevocationState == nsICertStorage::STATE_UNSET &&
mCRLiteTelemetryInfo) {
*mCRLiteTelemetryInfo = CRLiteTelemetryInfo::CertificateValid;
mCRLiteTelemetryInfo->mLookupResult =
CRLiteLookupResult::CertificateValid;
}
}
}
@ -902,7 +918,7 @@ Result NSSCertDBTrustDomain::CheckRevocation(
// responses from a failing server.
return SynchronousCheckRevocationWithServer(
certID, aiaLocation, time, maxOCSPLifetimeInDays, cachedResponseResult,
stapledOCSPResponseResult);
stapledOCSPResponseResult, crliteLookupDuration);
}
return HandleOCSPFailure(cachedResponseResult, stapledOCSPResponseResult,
@ -912,7 +928,8 @@ Result NSSCertDBTrustDomain::CheckRevocation(
Result NSSCertDBTrustDomain::SynchronousCheckRevocationWithServer(
const CertID& certID, const nsCString& aiaLocation, Time time,
uint16_t maxOCSPLifetimeInDays, const Result cachedResponseResult,
const Result stapledOCSPResponseResult) {
const Result stapledOCSPResponseResult,
const Maybe<TimeDuration>& crliteLookupDuration) {
uint8_t ocspRequestBytes[OCSP_REQUEST_MAX_LENGTH];
size_t ocspRequestLength;
@ -924,8 +941,20 @@ Result NSSCertDBTrustDomain::SynchronousCheckRevocationWithServer(
Vector<uint8_t> ocspResponse;
Input response;
TimeStamp ocspRequestBefore = TimeStamp::Now();
rv = DoOCSPRequest(aiaLocation, mOriginAttributes, ocspRequestBytes,
ocspRequestLength, GetOCSPTimeout(), ocspResponse);
TimeDuration ocspRequestDuration = TimeStamp::Now() - ocspRequestBefore;
if (mCRLiteMode != CRLiteMode::Disabled && crliteLookupDuration.isSome() &&
mCRLiteTelemetryInfo) {
if (*crliteLookupDuration < ocspRequestDuration) {
mCRLiteTelemetryInfo->mCRLiteFasterThanOCSPMillis.emplace(
(ocspRequestDuration - *crliteLookupDuration).ToMilliseconds());
} else {
mCRLiteTelemetryInfo->mOCSPFasterThanCRLiteMillis.emplace(
(*crliteLookupDuration - ocspRequestDuration).ToMilliseconds());
}
}
if (rv == Success &&
response.Init(ocspResponse.begin(), ocspResponse.length()) != Success) {
rv = Result::ERROR_OCSP_MALFORMED_RESPONSE; // too big

4
security/certverifier/NSSCertDBTrustDomain.h
View File

@ -268,8 +268,8 @@ class NSSCertDBTrustDomain : public mozilla::pkix::TrustDomain {
Result SynchronousCheckRevocationWithServer(
const mozilla::pkix::CertID& certID, const nsCString& aiaLocation,
mozilla::pkix::Time time, uint16_t maxOCSPLifetimeInDays,
const Result cachedResponseResult,
const Result stapledOCSPResponseResult);
const Result cachedResponseResult, const Result stapledOCSPResponseResult,
const Maybe<TimeDuration>& crliteLookupDuration);
Result HandleOCSPFailure(const Result cachedResponseResult,
const Result stapledOCSPResponseResult,
const Result error);

35
security/manager/ssl/SSLServerCertVerification.cpp
View File

@ -1015,7 +1015,7 @@ static void CollectCertTelemetry(
const PinningTelemetryInfo& aPinningTelemetryInfo,
const UniqueCERTCertList& aBuiltCertChain,
const CertificateTransparencyInfo& aCertificateTransparencyInfo,
CRLiteTelemetryInfo crliteTelemetryInfo) {
const CRLiteTelemetryInfo& aCRLiteTelemetryInfo) {
uint32_t evStatus = (aCertVerificationResult != Success)
? 0 // 0 = Failure
: (aEvOidPolicy == SEC_OID_UNKNOWN) ? 1 // 1 = DV
@ -1055,37 +1055,50 @@ static void CollectCertTelemetry(
/*isEV*/ aEvOidPolicy != SEC_OID_UNKNOWN, aCertificateTransparencyInfo);
}
switch (crliteTelemetryInfo) {
case CRLiteTelemetryInfo::FilterNotAvailable:
switch (aCRLiteTelemetryInfo.mLookupResult) {
case CRLiteLookupResult::FilterNotAvailable:
Telemetry::AccumulateCategorical(
Telemetry::LABELS_CRLITE_RESULT::FilterNotAvailable);
break;
case CRLiteTelemetryInfo::IssuerNotEnrolled:
case CRLiteLookupResult::IssuerNotEnrolled:
Telemetry::AccumulateCategorical(
Telemetry::LABELS_CRLITE_RESULT::IssuerNotEnrolled);
break;
case CRLiteTelemetryInfo::CertificateTooNew:
case CRLiteLookupResult::CertificateTooNew:
Telemetry::AccumulateCategorical(
Telemetry::LABELS_CRLITE_RESULT::CertificateTooNew);
break;
case CRLiteTelemetryInfo::CertificateValid:
case CRLiteLookupResult::CertificateValid:
Telemetry::AccumulateCategorical(
Telemetry::LABELS_CRLITE_RESULT::CertificateValid);
break;
case CRLiteTelemetryInfo::CertificateRevoked:
case CRLiteLookupResult::CertificateRevoked:
Telemetry::AccumulateCategorical(
Telemetry::LABELS_CRLITE_RESULT::CertificateRevoked);
break;
case CRLiteTelemetryInfo::LibraryFailure:
case CRLiteLookupResult::LibraryFailure:
Telemetry::AccumulateCategorical(
Telemetry::LABELS_CRLITE_RESULT::LibraryFailure);
break;
case CRLiteTelemetryInfo::NeverChecked:
case CRLiteLookupResult::NeverChecked:
break;
default:
MOZ_ASSERT_UNREACHABLE("Unhandled CRLiteTelemetryInfo value?");
MOZ_ASSERT_UNREACHABLE("Unhandled CRLiteLookupResult value?");
break;
}
if (aCRLiteTelemetryInfo.mCRLiteFasterThanOCSPMillis.isSome()) {
Telemetry::Accumulate(
Telemetry::CRLITE_FASTER_THAN_OCSP_MS,
static_cast<uint32_t>(
*aCRLiteTelemetryInfo.mCRLiteFasterThanOCSPMillis));
}
if (aCRLiteTelemetryInfo.mOCSPFasterThanCRLiteMillis.isSome()) {
Telemetry::Accumulate(
Telemetry::OCSP_FASTER_THAN_CRLITE_MS,
static_cast<uint32_t>(
*aCRLiteTelemetryInfo.mOCSPFasterThanCRLiteMillis));
}
}
static void AuthCertificateSetResults(
@ -1149,7 +1162,7 @@ Result AuthCertificate(CertVerifier& certVerifier,
SHA1ModeResult sha1ModeResult = SHA1ModeResult::NeverChecked;
PinningTelemetryInfo pinningTelemetryInfo;
CertificateTransparencyInfo certificateTransparencyInfo;
CRLiteTelemetryInfo crliteTelemetryInfo = CRLiteTelemetryInfo::NeverChecked;
CRLiteTelemetryInfo crliteTelemetryInfo;
nsTArray<nsTArray<uint8_t>> peerCertsBytes;
for (CERTCertListNode* n = CERT_LIST_HEAD(peerCertChain);

26
toolkit/components/telemetry/Histograms.json
View File

@ -11686,7 +11686,7 @@
"CRLITE_RESULT": {
"record_in_processes": ["main"],
"products": ["firefox"],
"expires_in_version": "80",
"expires_in_version": "75",
"kind": "categorical",
"labels": ["FilterNotAvailable", "IssuerNotEnrolled", "CertificateTooNew", "CertificateValid", "CertificateRevoked", "LibraryFailure"],
"description": "The result of looking up revocation information for a TLS server certificate in CRLite.",
@ -11694,6 +11694,30 @@
"releaseChannelCollection": "opt-out",
"alert_emails": ["dkeeler@mozilla.com", "jcj@mozilla.com", "seceng-telemetry@mozilla.com"]
},
"CRLITE_FASTER_THAN_OCSP_MS": {
"record_in_processes": ["main"],
"products": ["firefox"],
"expires_in_version": "75",
"kind": "exponential",
"high": 20000,
"n_buckets": 50,
"description": "If both a CRLite lookup and OCSP request are made, how many milliseconds faster was CRLite?",
"bug_numbers": [1602641],
"releaseChannelCollection": "opt-out",
"alert_emails": ["dkeeler@mozilla.com", "jcj@mozilla.com", "seceng-telemetry@mozilla.com"]
},
"OCSP_FASTER_THAN_CRLITE_MS": {
"record_in_processes": ["main"],
"products": ["firefox"],
"expires_in_version": "75",
"kind": "exponential",
"high": 20000,
"n_buckets": 50,
"description": "If both a CRLite lookup and OCSP request are made, how many milliseconds faster was OCSP?",
"bug_numbers": [1602641],
"releaseChannelCollection": "opt-out",
"alert_emails": ["dkeeler@mozilla.com", "jcj@mozilla.com", "seceng-telemetry@mozilla.com"]
},
"WEAVE_CONFIGURED_MASTER_PASSWORD": {
"record_in_processes": ["main", "content"],
"products": ["firefox", "fennec", "geckoview"],