chromeos: Avoid cryptohome D-Bus log spam at boot.

chrome/browser/chromeos/policy/enterprise_install_attributes.cc

Index: chrome/browser/chromeos/policy/enterprise_install_attributes.cc
diff --git a/chrome/browser/chromeos/policy/enterprise_install_attributes.cc b/chrome/browser/chromeos/policy/enterprise_install_attributes.cc
index c303e9ad6a37e36692a46ba3a1644dae99d7bb2d..9fd9c8033d815d1321be2198f0c036dd0156df2f 100644
--- a/chrome/browser/chromeos/policy/enterprise_install_attributes.cc
+++ b/chrome/browser/chromeos/policy/enterprise_install_attributes.cc
@@ -81,9 +81,9 @@ EnterpriseInstallAttributes::~EnterpriseInstallAttributes() {}
 void EnterpriseInstallAttributes::Init(const base::FilePath& cache_file) {
   DCHECK_EQ(false, device_locked_);
 
-  // The actual check happens asynchronously, thus it is ok to trigger it before
-  // Init() has completed.
-  TriggerConsistencyCheck(kDbusRetryCount * kDbusRetryIntervalInSeconds);

[Daniel Erat, 2016/08/11 21:34:43]

the multiplication by kDbusRetryIntervalInSeconds looks like a bug to me. the
method has the following signature:

  void EnterpriseInstallAttributes::TriggerConsistencyCheck(int dbus_retries)

and the argument indeed appears to be passed through to the callback as the
remaining number of retries. i don't see any reason for it to be multiplied by
the interval.

[Mattias Nissler (ping if slow), 2016/09/07 19:47:24]

Agreed.

[Daniel Erat, 2016/09/07 20:46:52]

Acknowledged.

+  cryptohome_client_->WaitForServiceToBeAvailable(base::Bind(
+      &EnterpriseInstallAttributes::OnCryptohomeServiceInitiallyAvailable,
+      weak_ptr_factory_.GetWeakPtr()));
 
   if (!base::PathExists(cache_file))
     return;
@@ -425,6 +425,16 @@ const char EnterpriseInstallAttributes::kAttrEnterpriseUser[] =
 const char EnterpriseInstallAttributes::kAttrConsumerKioskEnabled[] =
     "consumer.app_kiosk_enabled";
 
+void EnterpriseInstallAttributes::OnCryptohomeServiceInitiallyAvailable(
+    bool service_is_ready) {
+  if (!service_is_ready)
+    LOG(ERROR) << "Failed waiting for cryptohome D-Bus service availability";
+
+  // Start the consistency check even if we failed to wait for availability;
+  // hopefully the service will become available eventually.
+  TriggerConsistencyCheck(kDbusRetryCount);

[Daniel Erat, 2016/08/11 21:34:43]

calling this asynchronously when the service becomes available instead of
synchronously from Init() may have unintended consequences:

- TriggerConsistencyCheck() sets consistency_check_running_ to true
- LockDevice() defers locking if consistency_check_running_ is true

therefore, now that the running_ member is set to true asynchronously instead of
within Init(), there may be a possibility that LockDevice() could run before the
consistency check starts. when cryptohome later becomes available,
TriggerConsistencyCheck() might run while the device is in the process of being
locked.

LockDevice() appears to assume that cryptohome is ready, though (it calls
CryptohomeClient::InstallAttributesIsReady()), so perhaps it is only run much
later in response to a user action, long after cryptohome has become available
and the consistency check has started.

if the consistency check needs to run first, however, i could make Init()
synchronously set consistency_check_running_ to true and just defer the
consistency check's d-bus calls until the service is available. that way,
LockDevice() would continue to be blocked until the consistency check has run.

that might lead to slightly trickier code, though. let me know what you'd
prefer.

[Mattias Nissler (ping if slow), 2016/09/07 19:47:25]

I'd just set consistency_check_running_ to true in Init() - better safe than
sorry regarding sequencing of operations, since we've seen TPM initialization
taking minutes (!) on some devices. I don't think the code would become
significantly more tricky that way.

[Daniel Erat, 2016/09/07 20:46:52]

Done.

+}
+
 std::string EnterpriseInstallAttributes::GetDeviceModeString(DeviceMode mode) {
   switch (mode) {
     case DEVICE_MODE_CONSUMER: