Tether MessageTransferOperation: Only wait for a response from a host for a certain amount of time …

chromeos/components/tether/message_transfer_operation.cc

Index: chromeos/components/tether/message_transfer_operation.cc
diff --git a/chromeos/components/tether/message_transfer_operation.cc b/chromeos/components/tether/message_transfer_operation.cc
index d9d75cf72b1cd63fb5bbed455a8df36514d5d853..9f35107c4e27437d77cca082c51203b39a5d7047 100644
--- a/chromeos/components/tether/message_transfer_operation.cc
+++ b/chromeos/components/tether/message_transfer_operation.cc
@@ -7,6 +7,7 @@
 #include <set>
 
 #include "chromeos/components/tether/message_wrapper.h"
+#include "chromeos/components/tether/timer_factory.h"
 #include "components/proximity_auth/logging/logging.h"
 
 namespace chromeos {
@@ -35,12 +36,19 @@ std::vector<cryptauth::RemoteDevice> RemoveDuplicatesFromVector(
 // static
 uint32_t MessageTransferOperation::kMaxConnectionAttemptsPerDevice = 3;
 
+// static
+uint32_t MessageTransferOperation::kResponseTimeoutSeconds = 10;
+
 MessageTransferOperation::MessageTransferOperation(
     const std::vector<cryptauth::RemoteDevice>& devices_to_connect,
     BleConnectionManager* connection_manager)
     : remote_devices_(RemoveDuplicatesFromVector(devices_to_connect)),
       connection_manager_(connection_manager),
-      initialized_(false) {}
+      timer_factory_(base::MakeUnique<TimerFactory>()),
+      initialized_(false),
+      wait_for_response_(true),
+      response_timeout_seconds_(kResponseTimeoutSeconds),
+      weak_ptr_factory_(this) {}
 
 MessageTransferOperation::~MessageTransferOperation() {
   connection_manager_->RemoveObserver(this);
@@ -63,6 +71,7 @@ void MessageTransferOperation::Initialize() {
     cryptauth::SecureChannel::Status status;
     if (connection_manager_->GetStatusForDevice(remote_device, &status) &&
         status == cryptauth::SecureChannel::Status::AUTHENTICATED) {
+      StartResponseTimerForDevice(remote_device);
       OnDeviceAuthenticated(remote_device);
     }
   }
@@ -81,6 +90,7 @@ void MessageTransferOperation::OnSecureChannelStatusChanged(
   }
 
   if (new_status == cryptauth::SecureChannel::Status::AUTHENTICATED) {
+    StartResponseTimerForDevice(remote_device);
     OnDeviceAuthenticated(remote_device);
   } else if (old_status == cryptauth::SecureChannel::Status::AUTHENTICATING) {
     // If authentication fails, account details (e.g., BeaconSeeds) are not
@@ -139,6 +149,7 @@ void MessageTransferOperation::UnregisterDevice(
   remote_devices_.erase(std::remove(remote_devices_.begin(),
                                     remote_devices_.end(), remote_device),
                         remote_devices_.end());
+  StopResponseTimerForDevice(remote_device);
   connection_manager_->UnregisterRemoteDevice(remote_device,
                                               GetMessageTypeForConnection());
 
@@ -154,6 +165,42 @@ void MessageTransferOperation::SendMessageToDevice(
                                    message_wrapper->ToRawMessage());
 }
 
+void MessageTransferOperation::SetTimerFactoryForTest(
+    std::unique_ptr<TimerFactory> timer_factory_for_test) {
+  timer_factory_ = std::move(timer_factory_for_test);
+}
+
+void MessageTransferOperation::StartResponseTimerForDevice(

[khorimoto, 2017/05/31 17:26:35]

nit: Do you think a log is appropriate in this function?

[Ryan Hansberry, 2017/05/31 21:19:03]

Doesn't hurt; added.

+    const cryptauth::RemoteDevice& remote_device) {
+  if (!wait_for_response_)

[khorimoto, 2017/05/31 17:26:35]

Only call this function when we should wait for a response.

Then, this line should be a DCHECK() instead (except change to DCHECKing the
value returned by the ShouldWaitForResponse() function instead of an instance
field).

Same thing with StopResponseTimerForDevice() as well.

[Ryan Hansberry, 2017/05/31 21:19:03]

Good point, done.

+    return;
+
+  remote_device_to_timer_map_.emplace(remote_device,
+                                      timer_factory_->CreateOneShotTimer());
+  remote_device_to_timer_map_[remote_device]->Start(
+      FROM_HERE, base::TimeDelta::FromSeconds(response_timeout_seconds_),
+      base::Bind(&MessageTransferOperation::OnResponseTimeout,
+                 weak_ptr_factory_.GetWeakPtr(), remote_device));
+}
+
+void MessageTransferOperation::StopResponseTimerForDevice(
+    const cryptauth::RemoteDevice& remote_device) {
+  if (!wait_for_response_ || !remote_device_to_timer_map_[remote_device])

[khorimoto, 2017/05/31 17:26:35]

Instead of returning early if(!remote_device_to_timer_map_[remote_device]), just
don't ever call this function if a timer is not active. It should be pretty
simple - just remove the remote_device_to_timer_map_.erase(remote_device) call
in OnResponseTimeout() below.

[Ryan Hansberry, 2017/05/31 21:19:03]

That can't work, because this method is called from UnregisterDevice, which can
be called before OnDeviceAuthenticated is called (when the timer is created).
TLDR: it's valid for this method to be called without a timer existing. It also
just feels easier to reason about that timers are completely cleaned up after
being used.

[Kyle Horimoto, 2017/05/31 21:55:33]

Instead, can you change your code to make sure there is a timer before calling
this?

if (ShouldWaitForResponse() &&
    remote_device_to_timer_map_.find(remote_device) !=
remote_device_to_timer_map_.end()) {
   StopResponseTimerForDevice(remote_device);
}

[Ryan Hansberry, 2017/06/01 00:31:58]

What is the difference between checking if the map holds the timer inside or
outside of the method? The only difference I can see is that it's more
self-contained within the method.

[Kyle Horimoto, 2017/06/01 18:18:58]

Yep, I just wanted to make the method more clearly defined. In general, I try to
avoid functions called DoSomething() which don't actually do the thing they say
they do.

If you are set on this design, then change the function name (e.g.,
StopResponseTimerForDeviceIfActive()).

[Ryan Hansberry, 2017/06/01 18:44:09]

Done.

+    return;
+
+  remote_device_to_timer_map_[remote_device]->Stop();
+  remote_device_to_timer_map_.erase(remote_device);
+}
+
+void MessageTransferOperation::OnResponseTimeout(
+    const cryptauth::RemoteDevice& remote_device) {
+  PA_LOG(WARNING) << "Timed out while waiting for response from device with id "

[khorimoto, 2017/05/31 17:26:35]

nit: Capitalize ID.

[khorimoto, 2017/05/31 17:26:35]

In your log, also include the message type that was sent (the one on which
you're waiting for a response). See GetMessageTypeForConnection().

[Ryan Hansberry, 2017/05/31 21:19:03]

Done.

+                  << remote_device.GetTruncatedDeviceIdForLogs() << ".";
+
+  remote_device_to_timer_map_.erase(remote_device);
+  UnregisterDevice(remote_device);
+}
+
 }  // namespace tether
 
 }  // namespace chromeos