Wait for the attestation to be ready (TPM being prepared for attestation) before trying to enroll.

chromeos/attestation/attestation_flow_unittest.cc

Index: chromeos/attestation/attestation_flow_unittest.cc
diff --git a/chromeos/attestation/attestation_flow_unittest.cc b/chromeos/attestation/attestation_flow_unittest.cc
index 0b40dd66783890f4d1b27ffe8ec3261655b88999..6e1f0c7c5809ea7bdb6414e04de1c010ae881965 100644
--- a/chromeos/attestation/attestation_flow_unittest.cc
+++ b/chromeos/attestation/attestation_flow_unittest.cc
@@ -7,9 +7,13 @@
 
 #include "base/bind.h"
 #include "base/location.h"
+#include "base/memory/ptr_util.h"
 #include "base/run_loop.h"
 #include "base/single_thread_task_runner.h"
+#include "base/test/test_mock_time_task_runner.h"
 #include "base/threading/thread_task_runner_handle.h"
+#include "base/time/tick_clock.h"
+#include "base/timer/timer.h"
 #include "chromeos/attestation/mock_attestation_flow.h"
 #include "chromeos/cryptohome/cryptohome_parameters.h"
 #include "chromeos/cryptohome/mock_async_method_caller.h"
@@ -65,6 +69,16 @@ class FakeDBusData {
   std::string data_;
 };
 
+class ImpatientOneShotTimer : public base::OneShotTimer {
+ public:
+  void Start(const tracked_objects::Location& posted_from,
+             base::TimeDelta delay,
+             const base::Closure& user_task) override {
+    // Can't wait to fire!
+    user_task.Run();
+  }
+};
+
 }  // namespace
 
 class AttestationFlowTest : public testing::Test {
@@ -86,6 +100,93 @@ TEST_F(AttestationFlowTest, GetCertificate) {
       .InSequence(flow_order)
       .WillRepeatedly(Invoke(DBusCallbackFalse));
 
+  EXPECT_CALL(client, TpmAttestationIsPrepared(_))
+      .InSequence(flow_order)
+      .WillOnce(Invoke(DBusCallbackTrue));
+
+  // Use StrictMock when we want to verify invocation frequency.
+  StrictMock<cryptohome::MockAsyncMethodCaller> async_caller;
+  async_caller.SetUp(true, cryptohome::MOUNT_ERROR_NONE);
+  EXPECT_CALL(async_caller, AsyncTpmAttestationCreateEnrollRequest(_, _))
+      .Times(1)
+      .InSequence(flow_order);
+
+  std::unique_ptr<MockServerProxy> proxy(new StrictMock<MockServerProxy>());
+  proxy->DeferToFake(true);
+  EXPECT_CALL(*proxy, GetType()).WillRepeatedly(DoDefault());
+  EXPECT_CALL(
+      *proxy,
+      SendEnrollRequest(
+          cryptohome::MockAsyncMethodCaller::kFakeAttestationEnrollRequest, _))
+      .Times(1)
+      .InSequence(flow_order);
+
+  std::string fake_enroll_response =
+      cryptohome::MockAsyncMethodCaller::kFakeAttestationEnrollRequest;
+  fake_enroll_response += "_response";
+  EXPECT_CALL(async_caller,
+              AsyncTpmAttestationEnroll(_, fake_enroll_response, _))
+      .Times(1)
+      .InSequence(flow_order);
+
+  const AccountId account_id = AccountId::FromUserEmail("fake@test.com");
+  EXPECT_CALL(async_caller,
+              AsyncTpmAttestationCreateCertRequest(
+                  _, PROFILE_ENTERPRISE_USER_CERTIFICATE,
+                  cryptohome::Identification(account_id), "fake_origin", _))
+      .Times(1)
+      .InSequence(flow_order);
+
+  EXPECT_CALL(
+      *proxy,
+      SendCertificateRequest(
+          cryptohome::MockAsyncMethodCaller::kFakeAttestationCertRequest, _))
+      .Times(1)
+      .InSequence(flow_order);
+
+  std::string fake_cert_response =
+      cryptohome::MockAsyncMethodCaller::kFakeAttestationCertRequest;
+  fake_cert_response += "_response";
+  EXPECT_CALL(async_caller, AsyncTpmAttestationFinishCertRequest(
+                                fake_cert_response, KEY_USER,
+                                cryptohome::Identification(account_id),
+                                kEnterpriseUserKey, _))
+      .Times(1)
+      .InSequence(flow_order);
+
+  StrictMock<MockObserver> observer;
+  EXPECT_CALL(
+      observer,
+      MockCertificateCallback(
+          true, cryptohome::MockAsyncMethodCaller::kFakeAttestationCert))
+      .Times(1)
+      .InSequence(flow_order);
+  AttestationFlow::CertificateCallback mock_callback = base::Bind(
+      &MockObserver::MockCertificateCallback, base::Unretained(&observer));
+
+  std::unique_ptr<ServerProxy> proxy_interface(proxy.release());
+  AttestationFlow flow(&async_caller, &client, std::move(proxy_interface));
+  flow.GetCertificate(PROFILE_ENTERPRISE_USER_CERTIFICATE, account_id,
+                      "fake_origin", true, mock_callback);
+  Run();
+}
+
+TEST_F(AttestationFlowTest, GetCertificate_Attestation_Not_Prepared) {
+  // Verify the order of calls in a sequence.
+  Sequence flow_order;
+
+  // Use DBusCallbackFalse so the full enrollment flow is triggered.
+  chromeos::MockCryptohomeClient client;
+  EXPECT_CALL(client, TpmAttestationIsEnrolled(_))
+      .InSequence(flow_order)
+      .WillRepeatedly(Invoke(DBusCallbackFalse));
+
+  // It will take a bit for attestation to be prepared.
+  EXPECT_CALL(client, TpmAttestationIsPrepared(_))
+      .InSequence(flow_order)
+      .WillOnce(Invoke(DBusCallbackFalse))
+      .WillOnce(Invoke(DBusCallbackTrue));
+
   // Use StrictMock when we want to verify invocation frequency.
   StrictMock<cryptohome::MockAsyncMethodCaller> async_caller;
   async_caller.SetUp(true, cryptohome::MOUNT_ERROR_NONE);
@@ -144,11 +245,40 @@ TEST_F(AttestationFlowTest, GetCertificate) {
 
   std::unique_ptr<ServerProxy> proxy_interface(proxy.release());
   AttestationFlow flow(&async_caller, &client, std::move(proxy_interface));
+  flow.SetRetryTimerForTest(base::MakeUnique<ImpatientOneShotTimer>());
   flow.GetCertificate(PROFILE_ENTERPRISE_USER_CERTIFICATE, account_id,
                       "fake_origin", true, mock_callback);
   Run();
 }
 
+TEST_F(AttestationFlowTest, GetCertificate_Attestation_Never_Prepared) {

[The one and only Dr. Crash, 2016/12/02 06:31:40]

Something that is interesting here is that I see the logs showing that the
retries are after 0 ms, then 2, then 4, etc. etc. Here's the beginning of the
log during test.

[139700:139700:1201/222219.517837:3935294721413:WARNING:attestation_flow.cc(194)]
Attestation: not ready for attestation yet. Retrying in 0s ms.
[139700:139700:1201/222219.517942:3935294721516:WARNING:attestation_flow.cc(194)]
Attestation: not ready for attestation yet. Retrying in 1.9999s ms.
[139700:139700:1201/222219.518040:3935294721615:WARNING:attestation_flow.cc(194)]
Attestation: not ready for attestation yet. Retrying in 3.99991s ms.

It's interesting given that the initial delay is 2000 ms. However, I see that
net::BackoffEntry also uses the real clock (since I don't provide a special
TickClock to it) and that may be messing it up as it gets called very fast? I
haven't tried to follow all the math in the class when it calculates release
time.

I tried to use a task runner that can fast forward
(https://cs.chromium.org/chromium/src/base/test/test_mock_time_task_runner.h?r...,
as shown in
https://cs.chromium.org/chromium/src/testing/gtest/include/gtest/gtest.h?l=44...)
but none of the expected mock methods were called. If you have any good idea,
I'm all for it :)

+  StrictMock<cryptohome::MockAsyncMethodCaller> async_caller;
+  async_caller.SetUp(false, cryptohome::MOUNT_ERROR_NONE);
+
+  chromeos::MockCryptohomeClient client;
+  EXPECT_CALL(client, TpmAttestationIsEnrolled(_))
+      .WillRepeatedly(Invoke(DBusCallbackFalse));
+
+  EXPECT_CALL(client, TpmAttestationIsPrepared(_))
+      .WillRepeatedly(Invoke(DBusCallbackFalse));
+
+  // We're not expecting any server calls in this case; StrictMock will verify.
+  std::unique_ptr<MockServerProxy> proxy(new StrictMock<MockServerProxy>());
+  EXPECT_CALL(*proxy, GetType()).WillRepeatedly(DoDefault());
+
+  StrictMock<MockObserver> observer;
+  EXPECT_CALL(observer, MockCertificateCallback(false, "")).Times(1);
+  AttestationFlow::CertificateCallback mock_callback = base::Bind(
+      &MockObserver::MockCertificateCallback, base::Unretained(&observer));
+
+  std::unique_ptr<ServerProxy> proxy_interface(proxy.release());
+  AttestationFlow flow(&async_caller, &client, std::move(proxy_interface));
+  flow.SetRetryTimerForTest(base::MakeUnique<ImpatientOneShotTimer>());
+  flow.GetCertificate(PROFILE_ENTERPRISE_USER_CERTIFICATE, EmptyAccountId(), "",
+                      true, mock_callback);
+  Run();
+}
+
 TEST_F(AttestationFlowTest, GetCertificate_NoEK) {
   StrictMock<cryptohome::MockAsyncMethodCaller> async_caller;
   async_caller.SetUp(false, cryptohome::MOUNT_ERROR_NONE);
@@ -159,6 +289,9 @@ TEST_F(AttestationFlowTest, GetCertificate_NoEK) {
   EXPECT_CALL(client, TpmAttestationIsEnrolled(_))
       .WillRepeatedly(Invoke(DBusCallbackFalse));
 
+  EXPECT_CALL(client, TpmAttestationIsPrepared(_))
+      .WillOnce(Invoke(DBusCallbackTrue));
+
   // We're not expecting any server calls in this case; StrictMock will verify.
   std::unique_ptr<MockServerProxy> proxy(new StrictMock<MockServerProxy>());
   EXPECT_CALL(*proxy, GetType()).WillRepeatedly(DoDefault());
@@ -187,6 +320,9 @@ TEST_F(AttestationFlowTest, GetCertificate_EKRejected) {
   EXPECT_CALL(client, TpmAttestationIsEnrolled(_))
       .WillRepeatedly(Invoke(DBusCallbackFalse));
 
+  EXPECT_CALL(client, TpmAttestationIsPrepared(_))
+      .WillOnce(Invoke(DBusCallbackTrue));
+
   std::unique_ptr<MockServerProxy> proxy(new StrictMock<MockServerProxy>());
   proxy->DeferToFake(false);
   EXPECT_CALL(*proxy, GetType()).WillRepeatedly(DoDefault());
@@ -224,6 +360,9 @@ TEST_F(AttestationFlowTest, GetCertificate_FailEnroll) {
   EXPECT_CALL(client, TpmAttestationIsEnrolled(_))
       .WillRepeatedly(Invoke(DBusCallbackFalse));
 
+  EXPECT_CALL(client, TpmAttestationIsPrepared(_))
+      .WillOnce(Invoke(DBusCallbackTrue));
+
   std::unique_ptr<MockServerProxy> proxy(new StrictMock<MockServerProxy>());
   proxy->DeferToFake(true);
   EXPECT_CALL(*proxy, GetType()).WillRepeatedly(DoDefault());
@@ -462,6 +601,9 @@ TEST_F(AttestationFlowTest, AlternatePCA) {
   EXPECT_CALL(client, TpmAttestationIsEnrolled(_))
       .WillRepeatedly(Invoke(DBusCallbackFalse));
 
+  EXPECT_CALL(client, TpmAttestationIsPrepared(_))
+      .WillRepeatedly(Invoke(DBusCallbackTrue));
+
   NiceMock<cryptohome::MockAsyncMethodCaller> async_caller;
   async_caller.SetUp(true, cryptohome::MOUNT_ERROR_NONE);
   EXPECT_CALL(async_caller,