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

chromeos/attestation/attestation_flow.cc

Index: chromeos/attestation/attestation_flow.cc
diff --git a/chromeos/attestation/attestation_flow.cc b/chromeos/attestation/attestation_flow.cc
index c82cbe554008bf6f81cde6267570743de5e8c3b5..69a8997d9d501260088fb56cdd80eb3545c1b19b 100644
--- a/chromeos/attestation/attestation_flow.cc
+++ b/chromeos/attestation/attestation_flow.cc
@@ -4,9 +4,13 @@
 
 #include "chromeos/attestation/attestation_flow.h"
 
+#include <algorithm>
 #include <utility>
 
 #include "base/bind.h"
+#include "base/memory/ptr_util.h"
+#include "base/message_loop/message_loop.h"
+#include "base/timer/timer.h"
 #include "chromeos/cryptohome/async_method_caller.h"
 #include "chromeos/cryptohome/cryptohome_parameters.h"
 #include "chromeos/dbus/cryptohome_client.h"
@@ -17,6 +21,14 @@ namespace attestation {
 
 namespace {
 
+// A reasonable reay timeout that gives enough time for attestation

[Darren Krahn, 2016/12/08 18:06:06]

reay?

[The one and only Dr. Crash, 2016/12/08 19:41:10]

You know... Ready :)

+// to be prepared, yet does not make the caller wait too long.
+constexpr uint16_t kReadyTimeoutInSeconds = 180;

[Darren Krahn, 2016/12/08 18:06:05]

This does make the caller wait too long -- maybe just drop that comment at
least.

[The one and only Dr. Crash, 2016/12/13 22:37:17]

Changed to 60 s.

+
+// Delay before checking again whether the TPM has been prepared for
+// attestation.
+constexpr uint16_t kRetryDelayInSeconds = 9;

[Darren Krahn, 2016/12/08 18:06:06]

Too long IMO, why not every 300ms?

[The one and only Dr. Crash, 2016/12/08 19:41:10]

Sure. You know how quickly this should be ready better than me.

+
 // Redirects to one of three callbacks based on a boolean value and dbus call
 // status.
 //
@@ -29,10 +41,11 @@ namespace {
 void DBusBoolRedirectCallback(const base::Closure& on_true,
                               const base::Closure& on_false,
                               const base::Closure& on_fail,
+                              const std::string& on_fail_message,
                               DBusMethodCallStatus status,
                               bool value) {
   if (status != DBUS_METHOD_CALL_SUCCESS) {
-    LOG(ERROR) << "Attestation: Failed to query enrollment state.";
+    LOG(ERROR) << "Attestation: Failed to " << on_fail_message << ".";
     if (!on_fail.is_null())
       on_fail.Run();
     return;
@@ -95,6 +108,8 @@ AttestationFlow::AttestationFlow(cryptohome::AsyncMethodCaller* async_caller,
     : async_caller_(async_caller),
       cryptohome_client_(cryptohome_client),
       server_proxy_(std::move(server_proxy)),
+      ready_timeout_(base::TimeDelta::FromSeconds(kReadyTimeoutInSeconds)),
+      retry_delay_(base::TimeDelta::FromSeconds(kRetryDelayInSeconds)),
       weak_factory_(this) {}
 
 AttestationFlow::~AttestationFlow() {
@@ -108,24 +123,44 @@ void AttestationFlow::GetCertificate(
     const CertificateCallback& callback) {
   // If this device has not enrolled with the Privacy CA, we need to do that
   // first.  Once enrolled we can proceed with the certificate request.
-  base::Closure do_cert_request = base::Bind(
+  const base::Closure do_cert_request = base::Bind(
       &AttestationFlow::StartCertificateRequest, weak_factory_.GetWeakPtr(),
       certificate_profile, account_id, request_origin, force_new_key, callback);
-  base::Closure on_enroll_failure = base::Bind(callback, false, "");
-  base::Closure do_enroll = base::Bind(&AttestationFlow::StartEnroll,
-                                       weak_factory_.GetWeakPtr(),
-                                       on_enroll_failure,
-                                       do_cert_request);
-  cryptohome_client_->TpmAttestationIsEnrolled(base::Bind(
-      &DBusBoolRedirectCallback,
-      do_cert_request,  // If enrolled, proceed with cert request.
-      do_enroll,        // If not enrolled, initiate enrollment.
-      on_enroll_failure));
+  const base::Closure on_failure = base::Bind(callback, false, "");
+  const base::Closure initiate_enroll =
+      base::Bind(&AttestationFlow::InitiateEnroll, weak_factory_.GetWeakPtr(),
+                 on_failure, do_cert_request);
+  cryptohome_client_->TpmAttestationIsEnrolled(
+      base::Bind(&DBusBoolRedirectCallback,
+                 do_cert_request,  // If enrolled, proceed with cert request.
+                 initiate_enroll,  // If not enrolled, initiate enrollment.
+                 on_failure, "check enrollment state"));
+}
+
+void AttestationFlow::InitiateEnroll(const base::Closure& on_failure,

[Darren Krahn, 2016/12/08 18:06:05]

Eliminate this method? GetCertificate() can just as easily create a closure for
WaitForAttestationAndStartEnroll().

[The one and only Dr. Crash, 2016/12/08 19:41:10]

Yes. It used to be there because I allocated data but now that I do not it not
necessary to avoid allocating data unless we know the attetstion was not ready.

+                                     const base::Closure& next_task) {
+  WaitForAttestationReadyAndStartEnroll(
+      base::TimeTicks::Now() + ready_timeout_, on_failure,
+      base::Bind(&AttestationFlow::StartEnroll, weak_factory_.GetWeakPtr(),
+                 on_failure, next_task));
+}
+
+void AttestationFlow::WaitForAttestationReadyAndStartEnroll(
+    base::TimeTicks end_time,
+    const base::Closure& on_failure,
+    const base::Closure& next_task) {
+  const base::Closure retry_initiate_enroll =
+      base::Bind(&AttestationFlow::CheckAttestationReadyAndReschedule,
+                 weak_factory_.GetWeakPtr(), end_time, on_failure, next_task);
+  cryptohome_client_->TpmAttestationIsPrepared(
+      base::Bind(&DBusBoolRedirectCallback, next_task, retry_initiate_enroll,
+                 on_failure, "check for attestation readiness"));
 }
 
 void AttestationFlow::StartEnroll(const base::Closure& on_failure,
                                   const base::Closure& next_task) {
   // Get the attestation service to create a Privacy CA enrollment request.
+  LOG(WARNING) << "Start enroll";

[Darren Krahn, 2016/12/08 18:06:05]

Remove this?

[The one and only Dr. Crash, 2016/12/08 19:41:10]

Good catch. Thanks.

   async_caller_->AsyncTpmAttestationCreateEnrollRequest(
       server_proxy_->GetType(),
       base::Bind(&AttestationFlow::SendEnrollRequestToPCA,
@@ -211,18 +246,19 @@ void AttestationFlow::StartCertificateRequest(
                    callback));
   } else {
     // If the key already exists, query the existing certificate.
-    base::Closure on_key_exists = base::Bind(
+    const base::Closure on_key_exists = base::Bind(
         &AttestationFlow::GetExistingCertificate, weak_factory_.GetWeakPtr(),
         key_type, account_id, key_name, callback);
     // If the key does not exist, call this method back with |generate_new_key|
     // set to true.
-    base::Closure on_key_not_exists = base::Bind(
+    const base::Closure on_key_not_exists = base::Bind(
         &AttestationFlow::StartCertificateRequest, weak_factory_.GetWeakPtr(),
         certificate_profile, account_id, request_origin, true, callback);
     cryptohome_client_->TpmAttestationDoesKeyExist(
         key_type, cryptohome::Identification(account_id), key_name,
         base::Bind(&DBusBoolRedirectCallback, on_key_exists, on_key_not_exists,
-                   base::Bind(callback, false, "")));
+                   base::Bind(callback, false, ""),
+                   "check for existence of attestation key"));
   }
 }
 
@@ -277,6 +313,25 @@ void AttestationFlow::GetExistingCertificate(
       base::Bind(&DBusDataMethodCallback, callback));
 }
 
+void AttestationFlow::CheckAttestationReadyAndReschedule(
+    base::TimeTicks end_time,
+    const base::Closure& on_failure,
+    const base::Closure& next_task) {
+  if (base::TimeTicks::Now() < end_time) {

[Darren Krahn, 2016/12/08 18:06:05]

Now() can move if the system clock is changed, right? I'd prefer a max on the
number of retries so we don't end up with time related bugs.

[The one and only Dr. Crash, 2016/12/08 19:41:10]

Yes, but I wouldn't worry in this case... I did wrote it at some point with a
retry count (just dividing the timeout by the retry delay) but I'd rather have a
reasonably accurate timeout in the normal case than worry about the clock
changing (which, worst case, would mean a very long wait, but normally would
mean only wait until the attestation is ready, which will happen).

Also, a number of retries with a delay of 0 ms (or very very small retry
amounts) is a bit undefined... If we use a timeout, we will actually stop when
we reach that time.

If you feel very strongly about that, let me know... Because of the small retry
amounts, I would then either switch the API to #retries (which I really don't
like, because it means nothing in terms of UX), or enforce a minimum retry delay
of, say, 10 ms.

[Darren Krahn, 2016/12/09 22:27:15]

I think the worst case is a forward clock change and immediate timeout. But I'll
leave it up to you.

[The one and only Dr. Crash, 2016/12/13 22:37:17]

I think that's ok. The UI should have a retry mechanism if it cares to get the
certificate. I think maybe in another CL we could change the boolean nature of
the response to a status code and then it could know it has timed out.

+    LOG(WARNING) << "Attestation: Not prepared yet."
+                 << " Retrying in " << retry_delay_ << ".";
+    base::MessageLoop::current()->task_runner()->PostDelayedTask(
+        FROM_HERE,
+        base::Bind(&AttestationFlow::WaitForAttestationReadyAndStartEnroll,
+                   weak_factory_.GetWeakPtr(), end_time, on_failure, next_task),
+        retry_delay_);
+  } else {
+    LOG(ERROR) << "Attestation: Not prepared. Giving up on retrying.";
+    if (!on_failure.is_null())
+      on_failure.Run();
+  }
+}
+
 ServerProxy::~ServerProxy() {}
 
 PrivacyCAType ServerProxy::GetType() {