Certificate Provisioning: Handle server 412 error code

In this CL, the 412 pending approval HTTP status error code is handled
by the certificate provisioning client by trying the request after a
different delay depending on the request that received this error.

Bug: 1167055
Change-Id: Id92ea8f3bc47337144b3e81af2aa7c99a8aa465a
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2632687Reviewed-by: Michael Ershov <miersh@google.com>
Reviewed-by: Pavol Marko <pmarko@chromium.org>
Commit-Queue: Omar Morsi <omorsi@google.com>
Cr-Commit-Position: refs/heads/master@{#844568}

chrome/browser/chromeos/cert_provisioning/cert_provisioning_common.h

@@ -65,6 +65,14 @@ enum class CertProvisioningWorkerState {
   kMaxValue = kCanceled,
 };
 
+// Types of the requests sent from the certificate provisioning client to the
+// device management server.
+enum class DeviceManagementServerRequestType {
+  kStartCsr = 0,
+  kFinishCsr = 1,
+  kDownloadCert = 2,
+};
+
 // Returns true if the |state| is one of final states, i. e. worker should
 // finish its task in one of them.
 bool IsFinalState(CertProvisioningWorkerState state);

chrome/browser/chromeos/cert_provisioning/cert_provisioning_worker.cc

@@ -39,6 +39,23 @@ constexpr unsigned int kNonVaKeyModulusLengthBits = 2048;
 constexpr base::TimeDelta kMinumumTryAgainLaterDelay =
     base::TimeDelta::FromSeconds(10);
 
+// The delay after which a StartCsr request can be resent after a 412 Pending
+// Approval has been returned by the DM server.
+constexpr base::TimeDelta kRetryStartCsrRequestDelay =
+    base::TimeDelta::FromHours(1);
+// The delay after which a FinishCsr request can be resent after a 412 Pending
+// Approval has been returned by the DM server.
+constexpr base::TimeDelta kRetryFinishCsrRequestDelay =
+    base::TimeDelta::FromHours(1);
+// The delay after which a DownloadCsr request can be resent after a 412 Pending
+// Approval has been returned by the DM server.
+// Note: This request retry delay is more than other delays as a DownloadCsr
+// request may not only fail because of a DM server or a CES server problem but
+// also because of a problem with the Google Certificate Connecter which may
+// take more time to solve.
+constexpr base::TimeDelta kRetryDownloadCsrRequestDelay =
+    base::TimeDelta::FromHours(8);
+
 constexpr net::BackoffEntry::Policy kBackoffPolicy{
     /*num_errors_to_ignore=*/0,
     /*initial_delay_ms=*/30 * 1000 /* (30 seconds) */,
@@ -136,6 +153,18 @@ void MarkKeyAsCorporate(CertScope scope,
                          public_key_spki_der);
 }
 
+base::TimeDelta GetTryLaterDelayForRequestType(
+    DeviceManagementServerRequestType request_type) {
+  switch (request_type) {
+    case DeviceManagementServerRequestType::kStartCsr:
+      return kRetryStartCsrRequestDelay;
+    case DeviceManagementServerRequestType::kFinishCsr:
+      return kRetryFinishCsrRequestDelay;
+    case DeviceManagementServerRequestType::kDownloadCert:
+      return kRetryDownloadCsrRequestDelay;
+  }
+}
+
 }  // namespace
 
 // ============= CertProvisioningWorkerFactory =================================
@@ -439,7 +468,8 @@ void CertProvisioningWorkerImpl::OnStartCsrDone(
     const std::string& data_to_sign) {
   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
 
-  if (!ProcessResponseErrors(status, error, try_later)) {
+  if (!ProcessResponseErrors(DeviceManagementServerRequestType::kStartCsr,
+                             status, error, try_later)) {
     return;
   }
 
@@ -622,7 +652,8 @@ void CertProvisioningWorkerImpl::OnFinishCsrDone(
     base::Optional<int64_t> try_later) {
   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
 
-  if (!ProcessResponseErrors(status, error, try_later)) {
+  if (!ProcessResponseErrors(DeviceManagementServerRequestType::kFinishCsr,
+                             status, error, try_later)) {
     return;
   }
 
@@ -647,7 +678,8 @@ void CertProvisioningWorkerImpl::OnDownloadCertDone(
     const std::string& pem_encoded_certificate) {
   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
 
-  if (!ProcessResponseErrors(status, error, try_later)) {
+  if (!ProcessResponseErrors(DeviceManagementServerRequestType::kDownloadCert,
+                             status, error, try_later)) {
     return;
   }
 
@@ -695,6 +727,7 @@ void CertProvisioningWorkerImpl::OnImportCertDone(
 }
 
 bool CertProvisioningWorkerImpl::ProcessResponseErrors(
+    DeviceManagementServerRequestType request_type,
     policy::DeviceManagementStatus status,
     base::Optional<CertProvisioningResponseErrorType> error,
     base::Optional<int64_t> try_later) {
@@ -710,6 +743,18 @@ bool CertProvisioningWorkerImpl::ProcessResponseErrors(
     return false;
   }
 
+  if (status ==
+      policy::DeviceManagementStatus::DM_STATUS_SERVICE_ACTIVATION_PENDING) {
+    const base::TimeDelta try_later_delay =
+        GetTryLaterDelayForRequestType(request_type);
+    LOG(ERROR) << "A device management server request of type: "
+               << static_cast<int>(request_type)
+               << " will be retried after: " << try_later_delay;
+
+    ScheduleNextStep(std::move(try_later_delay));
+    return false;
+  }
+
   if (status != policy::DeviceManagementStatus::DM_STATUS_SUCCESS) {
     LOG(ERROR) << "DM Server returned error: " << status;
     UpdateState(CertProvisioningWorkerState::kFailed);

chrome/browser/chromeos/cert_provisioning/cert_provisioning_worker.h

@@ -216,7 +216,10 @@ class CertProvisioningWorkerImpl : public CertProvisioningWorker {
   void OnCleanUpDone();
 
   // Returns true if there are no errors and the flow can be continued.
+  // |request_type| is the type of the request to which the DM server has
+  // responded with the given |status|.
   bool ProcessResponseErrors(
+      DeviceManagementServerRequestType request_type,
       policy::DeviceManagementStatus status,
       base::Optional<CertProvisioningResponseErrorType> error,
       base::Optional<int64_t> try_later);

chrome/browser/chromeos/cert_provisioning/cert_provisioning_worker_unittest.cc

@@ -237,6 +237,21 @@ void VerifyDeleteKeyCalledOnce(CertScope cert_scope) {
             /*data_to_sign=*/""));                                           \
   }
 
+#define EXPECT_START_CSR_SERVICE_ACTIVATION_PENDING(START_CSR_FUNC)            \
+  {                                                                            \
+    EXPECT_CALL(cloud_policy_client_, START_CSR_FUNC)                          \
+        .Times(1)                                                              \
+        .WillOnce(RunOnceCallback<4>(policy::DeviceManagementStatus::          \
+                                         DM_STATUS_SERVICE_ACTIVATION_PENDING, \
+                                     /*response_error=*/base::nullopt,         \
+                                     /*try_again_later_ms=*/base::nullopt,     \
+                                     /*invalidation_topic=*/"",                \
+                                     /*va_challenge=*/"",                      \
+                                     enterprise_management::HashingAlgorithm:: \
+                                         HASHING_ALGORITHM_UNSPECIFIED,        \
+                                     /*data_to_sign=*/""));                    \
+  }
+
 #define EXPECT_START_CSR_INCONSISTENT_DATA(START_CSR_FUNC)                   \
   {                                                                          \
     EXPECT_CALL(cloud_policy_client_, START_CSR_FUNC)                        \
@@ -273,6 +288,15 @@ void VerifyDeleteKeyCalledOnce(CertScope cert_scope) {
             /*try_again_later_ms=*/(DELAY_MS)));                              \
   }
 
+#define EXPECT_FINISH_CSR_SERVICE_ACTIVATION_PENDING(FINISH_CSR_FUNC)          \
+  {                                                                            \
+    EXPECT_CALL(cloud_policy_client_, FINISH_CSR_FUNC)                         \
+        .Times(1)                                                              \
+        .WillOnce(RunOnceCallback<6>(policy::DeviceManagementStatus::          \
+                                         DM_STATUS_SERVICE_ACTIVATION_PENDING, \
+                                     base::nullopt, base::nullopt));           \
+  }
+
 #define EXPECT_DOWNLOAD_CERT_OK(DOWNLOAD_CERT_FUNC)                           \
   {                                                                           \
     EXPECT_CALL(cloud_policy_client_, DOWNLOAD_CERT_FUNC)                     \
@@ -281,6 +305,17 @@ void VerifyDeleteKeyCalledOnce(CertScope cert_scope) {
             policy::DeviceManagementStatus::DM_STATUS_SUCCESS, base::nullopt, \
             base::nullopt, kFakeCertificate));                                \
   }
+
+#define EXPECT_DOWNLOAD_CERT_SERVICE_ACTIVATION_PENDING(DOWNLOAD_CERT_FUNC)    \
+  {                                                                            \
+    EXPECT_CALL(cloud_policy_client_, DOWNLOAD_CERT_FUNC)                      \
+        .Times(1)                                                              \
+        .WillOnce(RunOnceCallback<4>(policy::DeviceManagementStatus::          \
+                                         DM_STATUS_SERVICE_ACTIVATION_PENDING, \
+                                     base::nullopt, base::nullopt,             \
+                                     kFakeCertificate));                       \
+  }
+
 #define EXPECT_DOWNLOAD_CERT_TRY_LATER(DOWNLOAD_CERT_FUNC, DELAY_MS)          \
   {                                                                           \
     EXPECT_CALL(cloud_policy_client_, DOWNLOAD_CERT_FUNC)                     \
@@ -948,6 +983,136 @@ TEST_F(CertProvisioningWorkerTest, TryLaterWait) {
   }
 }
 
+// Checks that when the device management server returns a
+// DM_STATUS_SERVICE_ACTIVATION_PENDING status error (which is 412 pending
+// approval) the server retries the request after the expected delay depending
+// on the request.
+TEST_F(CertProvisioningWorkerTest, ServiceActivationPendingResponse) {
+  CertProfile cert_profile(kCertProfileId, kCertProfileName,
+                           kCertProfileVersion,
+                           /*is_va_enabled=*/true, kCertProfileRenewalPeriod);
+
+  MockTpmChallengeKeySubtle* mock_tpm_challenge_key = PrepareTpmChallengeKey();
+  CertProvisioningWorkerImpl worker(
+      CertScope::kUser, GetProfile(), &testing_pref_service_, cert_profile,
+      &cloud_policy_client_, MakeInvalidator(), GetStateChangeCallback(),
+      GetResultCallback());
+
+  const TimeDelta kSmallDelay = TimeDelta::FromMilliseconds(500);
+  const TimeDelta kExpectedStartCsrDelay = TimeDelta::FromHours(1);
+  const TimeDelta kExpectedFinishCsrDelay = TimeDelta::FromHours(1);
+  const TimeDelta kExpectedDownloadCsrDelay = TimeDelta::FromHours(8);
+
+  EXPECT_CALL(state_change_callback_observer_, StateChangeCallback)
+      .Times(AtLeast(1));
+  {
+    testing::InSequence seq;
+
+    EXPECT_PREPARE_KEY_OK(
+        *mock_tpm_challenge_key,
+        StartPrepareKeyStep(attestation::AttestationKeyType::KEY_USER,
+                            /*will_register_key=*/true,
+                            GetKeyName(kCertProfileId),
+                            /*profile=*/_,
+                            /*callback=*/_));
+
+    EXPECT_START_CSR_SERVICE_ACTIVATION_PENDING(ClientCertProvisioningStartCsr(
+        kCertScopeStrUser, kCertProfileId, kCertProfileVersion, GetPublicKey(),
+        /*callback=*/_));
+
+    worker.DoStep();
+    EXPECT_EQ(worker.GetState(),
+              CertProvisioningWorkerState::kKeypairGenerated);
+  }
+
+  {
+    testing::InSequence seq;
+
+    // Verify that nothing happens after half of the expected StartCsr delay.
+    FastForwardBy(kExpectedStartCsrDelay / 2);
+    Mock::VerifyAndClearExpectations(&cloud_policy_client_);
+
+    EXPECT_START_CSR_OK(
+        ClientCertProvisioningStartCsr(kCertScopeStrUser, kCertProfileId,
+                                       kCertProfileVersion, GetPublicKey(),
+                                       /*callback=*/_),
+        em::HashingAlgorithm::SHA256);
+
+    EXPECT_SIGN_CHALLENGE_OK(*mock_tpm_challenge_key,
+                             StartSignChallengeStep(kChallenge,
+                                                    /*callback=*/_));
+
+    EXPECT_REGISTER_KEY_OK(*mock_tpm_challenge_key, StartRegisterKeyStep);
+
+    EXPECT_CALL(
+        *key_permissions_manager_,
+        AllowKeyForUsage(/*callback=*/_, platform_keys::KeyUsage::kCorporate,
+                         GetPublicKey()));
+
+    EXPECT_SET_ATTRIBUTE_FOR_KEY_OK(SetAttributeForKey(
+        platform_keys::TokenId::kUser, GetPublicKey(),
+        platform_keys::KeyAttributeType::kCertificateProvisioningId,
+        kCertProfileId, _));
+
+    EXPECT_SIGN_RSAPKC1_DIGEST_OK(SignRSAPKCS1Digest(
+        ::testing::Optional(platform_keys::TokenId::kUser), kDataToSign,
+        GetPublicKey(), platform_keys::HashAlgorithm::HASH_ALGORITHM_SHA256,
+        /*callback=*/_));
+
+    EXPECT_FINISH_CSR_SERVICE_ACTIVATION_PENDING(
+        ClientCertProvisioningFinishCsr(
+            kCertScopeStrUser, kCertProfileId, kCertProfileVersion,
+            GetPublicKey(), kChallengeResponse, kSignature, /*callback=*/_));
+
+    FastForwardBy(kExpectedStartCsrDelay / 2 + kSmallDelay);
+    EXPECT_EQ(worker.GetState(), CertProvisioningWorkerState::kSignCsrFinished);
+  }
+
+  {
+    testing::InSequence seq;
+
+    // Verify that nothing happens after half of the expected FinishCsr delay.
+    FastForwardBy(kExpectedFinishCsrDelay / 2);
+    Mock::VerifyAndClearExpectations(&cloud_policy_client_);
+
+    EXPECT_FINISH_CSR_OK(ClientCertProvisioningFinishCsr(
+        kCertScopeStrUser, kCertProfileId, kCertProfileVersion, GetPublicKey(),
+        kChallengeResponse, kSignature, /*callback=*/_));
+
+    EXPECT_DOWNLOAD_CERT_SERVICE_ACTIVATION_PENDING(
+        ClientCertProvisioningDownloadCert(kCertScopeStrUser, kCertProfileId,
+                                           kCertProfileVersion, GetPublicKey(),
+                                           /*callback=*/_));
+
+    FastForwardBy(kExpectedFinishCsrDelay / 2 + kSmallDelay);
+    EXPECT_EQ(worker.GetState(),
+              CertProvisioningWorkerState::kFinishCsrResponseReceived);
+  }
+
+  {
+    testing::InSequence seq;
+
+    // Verify that nothing happens after half of the expected DownloadCert
+    // delay.
+    FastForwardBy(kExpectedDownloadCsrDelay / 2);
+    Mock::VerifyAndClearExpectations(&cloud_policy_client_);
+
+    EXPECT_DOWNLOAD_CERT_OK(ClientCertProvisioningDownloadCert);
+
+    EXPECT_IMPORT_CERTIFICATE_OK(ImportCertificate(
+        platform_keys::TokenId::kUser, /*certificate=*/_, /*callback=*/_));
+
+    EXPECT_EQ(worker.GetState(),
+              CertProvisioningWorkerState::kFinishCsrResponseReceived);
+
+    EXPECT_CALL(callback_observer_,
+                Callback(cert_profile, CertProvisioningWorkerState::kSucceeded))
+        .Times(1);
+    FastForwardBy(kExpectedDownloadCsrDelay / 2 + kSmallDelay);
+    EXPECT_EQ(worker.GetState(), CertProvisioningWorkerState::kSucceeded);
+  }
+}
+
 // Checks that when the server returns try_again_later field, the worker will
 // retry when the invalidation is triggered.
 TEST_F(CertProvisioningWorkerTest, InvalidationRespected) {